Use logger API everywhere

271fed1b · Léo-Paul Géneau · da38a71c · 271fed1b · 271fed1b · 271fed1b
Commit 271fed1b authored Oct 19, 2022 by Léo-Paul Géneau 👾
19 changed files
--- a/pimdm/Config.py
+++ b/pimdm/Config.py
--- a/pimdm/Interface.py
+++ b/pimdm/Interface.py
+import logging
 import socket
 from abc import ABCMeta, abstractmethod
 import threading
@@ -40,9 +41,8 @@ class Interface(metaclass=ABCMeta):
                (raw_bytes, ancdata, _, src_addr) = self._recv_socket.recvmsg(256 * 1024, 500)
                if raw_bytes:
                    self._receive(raw_bytes, ancdata, src_addr)
-            except Exception:
+            except Exception as e:
-                traceback.print_exc()
+                logging.error(e, exc_info=True)
-                continue
    @abstractmethod
    def _receive(self, raw_bytes, ancdata, src_addr):

--- a/pimdm/InterfacePIM.py
+++ b/pimdm/InterfacePIM.py
@@ -2,7 +2,6 @@ import socket
 import random
 import logging
 import netifaces
-import traceback
 from threading import Timer
 from pimdm.Interface import Interface
@@ -51,7 +50,10 @@ class InterfacePim(Interface):
        self._had_neighbors = False
        self.neighbors = {}
        self.neighbors_lock = RWLockWrite()
-        self.interface_logger = logging.LoggerAdapter(InterfacePim.LOGGER, {'vif': vif_index, 'interfacename': interface_name})
+        self.interface_logger = logging.LoggerAdapter(
+          InterfacePim.LOGGER,
+          {'tree': None, 'vif': vif_index, 'interfacename': interface_name, 'routername': None},
+        )
        # SOCKET
        if_addr_dict = netifaces.ifaddresses(interface_name)
@@ -272,7 +274,7 @@ class InterfacePim(Interface):
        Receive an Hello packet
        """
        ip = packet.ip_header.ip_src
-        print("ip = ", ip)
+        logging.debug("ip = %s", ip)
        options = packet.payload.payload.get_options()
        if (1 in options) and (20 in options):
@@ -287,7 +289,7 @@ class InterfacePim(Interface):
            if ip not in self.neighbors:
                if hello_hold_time == 0:
                    return
-                print("ADD NEIGHBOR")
+                logging.debug("ADD NEIGHBOR")
                from pimdm.Neighbor import Neighbor
                self.neighbors[ip] = Neighbor(self, ip, generation_id, hello_hold_time, state_refresh_capable)
                self.force_send_hello()
@@ -310,8 +312,8 @@ class InterfacePim(Interface):
        try:
            self.get_kernel().get_routing_entry(source_group).recv_assert_msg(self.vif_index, packet)
-        except:
+        except Exception as e:
-            traceback.print_exc()
+            logging.error(e, exc_info=True)
    def receive_join_prune(self, packet):
        """
@@ -329,17 +331,15 @@ class InterfacePim(Interface):
                source_group = (source_address, multicast_group)
                try:
                    self.get_kernel().get_routing_entry(source_group).recv_join_msg(self.vif_index, packet)
-                except:
+                except Exception as e:
-                    traceback.print_exc()
+                    logging.error(e, exc_info=True)
-                    continue
            for source_address in pruned_src_addresses:
                source_group = (source_address, multicast_group)
                try:
                    self.get_kernel().get_routing_entry(source_group).recv_prune_msg(self.vif_index, packet)
-                except:
+                except Exception as e:
-                    traceback.print_exc()
+                    logging.error(e, exc_info=True)
-                    continue
    def receive_graft(self, packet):
        """
@@ -356,9 +356,8 @@ class InterfacePim(Interface):
                source_group = (source_address, multicast_group)
                try:
                    self.get_kernel().get_routing_entry(source_group).recv_graft_msg(self.vif_index, packet)
-                except:
+                except Exception as e:
-                    traceback.print_exc()
+                    logging.error(e, exc_info=True)
-                    continue
    def receive_graft_ack(self, packet):
        """
@@ -375,9 +374,8 @@ class InterfacePim(Interface):
                source_group = (source_address, multicast_group)
                try:
                    self.get_kernel().get_routing_entry(source_group).recv_graft_ack_msg(self.vif_index, packet)
-                except:
+                except Exception as e:
-                    traceback.print_exc()
+                    logging.error(e, exc_info=True)
-                    continue
    def receive_state_refresh(self, packet):
        """
@@ -392,8 +390,8 @@ class InterfacePim(Interface):
        source_group = (source, group)
        try:
            self.get_kernel().get_routing_entry(source_group).recv_state_refresh_msg(self.vif_index, packet)
-        except:
+        except Exception as e:
-            traceback.print_exc()
+            logging.error(e, exc_info=True)
    def receive_unknown(self, packet):
        """

--- a/pimdm/InterfacePIM6.py
+++ b/pimdm/InterfacePIM6.py
@@ -40,7 +40,10 @@ class InterfacePim6(InterfacePim):
        self._had_neighbors = False
        self.neighbors = {}
        self.neighbors_lock = RWLockWrite()
-        self.interface_logger = logging.LoggerAdapter(InterfacePim.LOGGER, {'vif': vif_index, 'interfacename': interface_name})
+        self.interface_logger = logging.LoggerAdapter(
+          InterfacePim.LOGGER,
+          {'tree': None, 'vif': vif_index, 'interfacename': interface_name, 'routername': None},
+        )
        # SOCKET
        s = socket.socket(socket.AF_INET6, socket.SOCK_RAW, socket.IPPROTO_PIM)

--- a/pimdm/Kernel.py
+++ b/pimdm/Kernel.py
@@ -2,7 +2,7 @@ import os
 import socket
 import struct
 import ipaddress
-import traceback
+import logging
 from socket import if_nametoindex
 from threading import RLock, Thread
 from abc import abstractmethod, ABCMeta
@@ -47,8 +47,11 @@ class Kernel(metaclass=ABCMeta):
        self.membership_interface = {}  # name: interface_igmp or interface_mld
        # logs
-        self.interface_logger = Main.logger.getChild('KernelInterface')
+        self.interface_logger = logging.LoggerAdapter(
-        self.tree_logger = Main.logger.getChild('KernelTree')
+          logging.getLogger('pim.KernelInterface'),
+          {'tree': None, 'vif': None, 'interfacename': None, 'routername': None},
+        )
+        self.tree_logger = logging.getLogger('pim.KernelTree')
        # receive signals from kernel with a background thread
        self.handler_thread = Thread(target=self.handler)
@@ -302,8 +305,8 @@ class Kernel4(Kernel):
        if pim_globals.MULTICAST_TABLE_ID != 0:
            try:
                s.setsockopt(socket.IPPROTO_IP, self.MRT_TABLE, pim_globals.MULTICAST_TABLE_ID)
-            except:
+            except Exception as e:
-                traceback.print_exc()
+                logging.error(e, exc_info=True)
        # MRT INIT
        s.setsockopt(socket.IPPROTO_IP, self.MRT_INIT, 1)
@@ -446,35 +449,34 @@ class Kernel4(Kernel):
            try:
                msg = self.socket.recv(20)
                (_, _, im_msgtype, im_mbz, im_vif, _, im_src, im_dst) = struct.unpack("II B B B B 4s 4s", msg[:20])
-                print((im_msgtype, im_mbz, socket.inet_ntoa(im_src), socket.inet_ntoa(im_dst)))
+                logging.debug((im_msgtype, im_mbz, socket.inet_ntoa(im_src), socket.inet_ntoa(im_dst)))
                if im_mbz != 0:
                    continue
-                print(im_msgtype)
+                logging.debug(im_msgtype)
-                print(im_mbz)
+                logging.debug(im_mbz)
-                print(im_vif)
+                logging.debug(im_vif)
-                print(socket.inet_ntoa(im_src))
+                logging.debug(socket.inet_ntoa(im_src))
-                print(socket.inet_ntoa(im_dst))
+                logging.debug(socket.inet_ntoa(im_dst))
                #print((im_msgtype, im_mbz, socket.inet_ntoa(im_src), socket.inet_ntoa(im_dst)))
                ip_src = socket.inet_ntoa(im_src)
                ip_dst = socket.inet_ntoa(im_dst)
                if im_msgtype == self.IGMPMSG_NOCACHE:
-                    print("IGMP NO CACHE")
+                    logging.debug("IGMP NO CACHE")
                    self.igmpmsg_nocache_handler(ip_src, ip_dst, im_vif)
                elif im_msgtype == self.IGMPMSG_WRONGVIF:
-                    print("WRONG VIF HANDLER")
+                    logging.debug("WRONG VIF HANDLER")
                    self.igmpmsg_wrongvif_handler(ip_src, ip_dst, im_vif)
                #elif im_msgtype == Kernel.IGMPMSG_WHOLEPKT:
                #    print("IGMP_WHOLEPKT")
                #    self.igmpmsg_wholepacket_handler(ip_src, ip_dst)
                else:
                    raise Exception
-            except Exception:
+            except Exception as e:
-                traceback.print_exc()
+                logging.error(e, exc_info=True)
-                continue
    # receive multicast (S,G) packet and multicast routing table has no (S,G) entry
    def igmpmsg_nocache_handler(self, ip_src, ip_dst, iif):
@@ -545,8 +547,8 @@ class Kernel6(Kernel):
        if pim_globals.MULTICAST_TABLE_ID != 0:
            try:
                s.setsockopt(socket.IPPROTO_IPV6, self.MRT6_TABLE, pim_globals.MULTICAST_TABLE_ID)
-            except:
+            except Exception as e:
-                traceback.print_exc()
+                logging.error(e, exc_info=True)
        # MRT INIT
        s.setsockopt(socket.IPPROTO_IPV6, self.MRT6_INIT, 1)
@@ -718,30 +720,29 @@ class Kernel6(Kernel):
                if im6_mbz != 0:
                    continue
-                print(im6_mbz)
+                logging.debug(im6_mbz)
-                print(im6_msgtype)
+                logging.debug(im6_msgtype)
-                print(im6_mif)
+                logging.debug(im6_mif)
-                print(socket.inet_ntop(socket.AF_INET6, im6_src))
+                logging.debug(socket.inet_ntop(socket.AF_INET6, im6_src))
-                print(socket.inet_ntop(socket.AF_INET6, im6_dst))
+                logging.debug(socket.inet_ntop(socket.AF_INET6, im6_dst))
                # print((im_msgtype, im_mbz, socket.inet_ntoa(im_src), socket.inet_ntoa(im_dst)))
                ip_src = socket.inet_ntop(socket.AF_INET6, im6_src)
                ip_dst = socket.inet_ntop(socket.AF_INET6, im6_dst)
                if im6_msgtype == self.MRT6MSG_NOCACHE:
-                    print("MRT6 NO CACHE")
+                    logging.debug("MRT6 NO CACHE")
                    self.msg_nocache_handler(ip_src, ip_dst, im6_mif)
                elif im6_msgtype == self.MRT6MSG_WRONGMIF:
-                    print("WRONG MIF HANDLER")
+                    logging.debug("WRONG MIF HANDLER")
                    self.msg_wrongvif_handler(ip_src, ip_dst, im6_mif)
                # elif im_msgtype == Kernel.IGMPMSG_WHOLEPKT:
                #    print("IGMP_WHOLEPKT")
                #    self.igmpmsg_wholepacket_handler(ip_src, ip_dst)
                else:
                    raise Exception
-            except Exception:
+            except Exception as e:
-                traceback.print_exc()
+                logging.error(e, exc_info=True)
-                continue
    # receive multicast (S,G) packet and multicast routing table has no (S,G) entry
    def msg_nocache_handler(self, ip_src, ip_dst, iif):

--- a/pimdm/Main.py
+++ b/pimdm/Main.py
@@ -3,7 +3,7 @@ import sys
 import time
 import netifaces
 import logging
-import logging.handlers
+import logging.config
 from prettytable import PrettyTable
 from pimdm.tree import pim_globals
@@ -17,7 +17,6 @@ mld_interfaces = {}  # mld interfaces
 kernel = None
 kernel_v6 = None
 unicast_routing = None
-logger = None
 def add_pim_interface(interface_name, state_refresh_capable: bool = False, ipv4=True, ipv6=False):
@@ -80,7 +79,7 @@ def list_neighbors(ipv4=False, ipv6=False):
            t.add_row(
                [interface.interface_name, neighbor.ip, neighbor.hello_hold_time, neighbor.generation_id, time.strftime("%H:%M:%S", time.gmtime(uptime))])
-    print(t)
+    logging.info(t)
    return str(t)
@@ -114,7 +113,7 @@ def list_enabled_interfaces(ipv4=False, ipv6=False):
            t.add_row([interface, ip, enabled, state_refresh_enabled, membership_state])
        except Exception:
            continue
-    print(t)
+    logging.info(t)
    return str(t)
@@ -141,10 +140,10 @@ def list_membership_state(ipv4=True, ipv6=False):
    for (interface_name, interface_obj) in list(membership_interfaces.items()):
        interface_state = interface_obj.interface_state
        state_txt = interface_state.print_state()
-        print(interface_state.group_state.items())
+        logging.info(interface_state.group_state.items())
        for (group_addr, group_state) in list(interface_state.group_state.items()):
-            print(group_addr)
+            logging.info(group_addr)
            group_state_txt = group_state.print_state()
            t.add_row([interface_name, state_txt, group_addr, group_state_txt])
    return str(t)
@@ -242,9 +241,8 @@ def set_config(file_path):
    from . import Config
    try:
        Config.parse_config_file(file_path)
-    except:
+    except Exception as e:
-        import traceback
+        logging.error(e, exc_info=True)
-        traceback.print_exc()
 def drop(interface_name, packet_type):
@@ -268,23 +266,6 @@ def enable_ipv6_kernel():
 def main():
-    # logging
-    global logger
-    logger = logging.getLogger('pim')
-    mld_logger = logging.getLogger('mld')
-    igmp_logger = logging.getLogger('igmp')
-    logger.setLevel(logging.DEBUG)
-    igmp_logger.setLevel(logging.DEBUG)
-    mld_logger.setLevel(logging.DEBUG)
-    handler = logging.StreamHandler(sys.stdout)
-    handler.addFilter(RootFilter(""))
-    handler.setLevel(logging.DEBUG)
-    handler.setFormatter(logging.Formatter('%(asctime)-20s %(name)-50s %(tree)-35s %(vif)-2s %(interfacename)-5s '
-                                           '%(routername)-2s %(message)s'))
-    logger.addHandler(handler)
-    igmp_logger.addHandler(handler)
-    mld_logger.addHandler(handler)
    global kernel
    from pimdm.Kernel import Kernel4
    kernel = Kernel4()

--- a/pimdm/Neighbor.py
+++ b/pimdm/Neighbor.py
@@ -19,9 +19,10 @@ class Neighbor:
        logger_info = dict(contact_interface.interface_logger.extra)
        logger_info['neighbor_ip'] = ip
        self.neighbor_logger = logging.LoggerAdapter(self.LOGGER, logger_info)
-        self.neighbor_logger.debug('Monitoring new neighbor ' + ip + ' with GenerationID: ' + str(generation_id) +
+        self.neighbor_logger.debug(
-                                   '; HelloHoldTime: ' + str(hello_hold_time) + '; StateRefreshCapable: ' +
+            'Monitoring new neighbor %s with GenerationID: %s; HelloHoldTime: %s; StateRefreshCapable: %s',
-                                   str(state_refresh_capable))
+            ip, generation_id, hello_hold_time, state_refresh_capable
+        )
        self.contact_interface = contact_interface
        self.ip = ip
        self.generation_id = generation_id
@@ -45,9 +46,9 @@ class Neighbor:
        if hello_hold_time == HELLO_HOLD_TIME_TIMEOUT:
            self.remove()
-            self.neighbor_logger.debug('Detected neighbor removal of ' + self.ip)
+            self.neighbor_logger.debug('Detected neighbor removal of %s', self.ip)
        elif hello_hold_time != HELLO_HOLD_TIME_NO_TIMEOUT:
-            self.neighbor_logger.debug('Neighbor Liveness Timer reseted of ' + self.ip)
+            self.neighbor_logger.debug('Neighbor Liveness Timer reseted of %s', self.ip)
            self.neighbor_liveness_timer = Timer(hello_hold_time, self.remove)
            self.neighbor_liveness_timer.start()
        else:
@@ -74,7 +75,7 @@ class Neighbor:
    """
    def remove(self):
-        print('HELLO TIMER EXPIRED... remove neighbor')
+        logging.debug('HELLO TIMER EXPIRED... remove neighbor')
        if self.neighbor_liveness_timer is not None:
            self.neighbor_liveness_timer.cancel()
        self.neighbor_logger.debug('Neighbor Liveness Timer expired of ' + self.ip)

--- a/pimdm/Run.py
+++ b/pimdm/Run.py
 #!/usr/bin/env python3
-import argparse, glob, os, signal, socket, sys, traceback
+import argparse, glob, logging, os, signal, socket, sys
 import _pickle as pickle
 from prettytable import PrettyTable
@@ -16,6 +16,55 @@ PROCESS_LOG_FOLDER = '/var/log/pimdm'
 PROCESS_LOG_STDOUT_FILE = os.path.join(PROCESS_LOG_FOLDER, 'stdout{}')
 PROCESS_LOG_STDERR_FILE = os.path.join(PROCESS_LOG_FOLDER, 'stderror{}')
+LOG_CONFIG = {
+    'version': 1,
+    'formatters': {
+        'detailed': {
+            'class': 'logging.Formatter',
+            'format': '%(asctime)-20s %(name)-50s %(tree)-35s %(vif)-2s %(interfacename)-5s %(routername)-2s %(message)s',
+        },
+    },
+    'handlers': {
+        'console': {
+            'class': 'logging.StreamHandler',
+            'stream': 'ext://sys.stdout',
+        },
+        'file': {
+            'class': 'logging.FileHandler',
+        },
+        'errors': {
+            'class': 'logging.FileHandler',
+            'level': 'ERROR',
+        },
+        'console_detailed': {
+            'class': 'logging.StreamHandler',
+            'stream': 'ext://sys.stdout',
+            'formatter': 'detailed',
+        },
+        'file_detailed': {
+            'class': 'logging.FileHandler',
+            'formatter': 'detailed',
+        },
+    },
+    'loggers': {
+        'pim': {
+            'handlers': ['console_detailed', 'file_detailed'],
+            'propagate': False,
+        },
+        'mld': {
+            'handlers': ['console_detailed', 'file_detailed'],
+            'propagate': False,
+        },
+        'igmp': {
+            'handlers': ['console_detailed', 'file_detailed'],
+            'propagate': False,
+        },
+    },
+    'root': {
+        'handlers': ['console', 'file', 'errors'],
+    },
+}
 def clean_process_dir():
    os.remove(process_file_path())
    os.remove(process_socket_path())
@@ -52,8 +101,8 @@ def main_loop(sock):
        try:
            connection, client_address = sock.accept()
            data = connection.recv(256 * 1024)
-            print(sys.stderr, 'sending data back to the client')
+            logging.debug('sending data back to the client')
-            print(pickle.loads(data))
+            logging.debug(pickle.loads(data))
            args = pickle.loads(data)
            if 'ipv4' not in args and 'ipv6' not in args or not (args.ipv4 or args.ipv6):
                args.ipv4 = True
@@ -101,7 +150,7 @@ def main_loop(sock):
        except Exception as e:
            connection.sendall(pickle.dumps(e))
            connection.shutdown(socket.SHUT_RDWR)
-            traceback.print_exc()
+            logging.error(e, exc_info=True)
        finally:
            # Clean up the connection
            if 'connection' in locals():
@@ -109,6 +158,7 @@ def main_loop(sock):
 def args_parser():
    parser = argparse.ArgumentParser(description='PIM-DM protocol', prog='pim-dm')
+    parser.add_argument("-v", "--verbose", action="store_true", default=False, help="Verbose (print all debug messages)")
    group = parser.add_mutually_exclusive_group(required=True)
    group.add_argument("-start", "--start", action="store_true", default=False, help="Start PIM")
    group.add_argument("-stop", "--stop", action="store_true", default=False, help="Stop PIM")
@@ -132,7 +182,6 @@ def args_parser():
                                                                                            "Use -4 or -6 to specify IPv4 or IPv6 interface.")
    group.add_argument("-riigmp", "--remove_interface_igmp", nargs=1, metavar='INTERFACE_NAME', help="Remove IGMP interface")
    group.add_argument("-rimld", "--remove_interface_mld", nargs=1, metavar='INTERFACE_NAME', help="Remove MLD interface")
-    group.add_argument("-v", "--verbose", action="store_true", default=False, help="Verbose (print all debug messages)")
    group.add_argument("-t", "--test", nargs=2, metavar=('ROUTER_NAME', 'SERVER_LOG_IP'), help="Tester... send log information to SERVER_LOG_IP. Set the router name to ROUTER_NAME")
    group.add_argument("-config", "--config", nargs=1, metavar='CONFIG_FILE_PATH', type=str,
                       help="File path for configuration file.")
@@ -164,9 +213,9 @@ def list_instances(args):
        t_new = client_socket(args, print_output=False)
        t.add_row(t_new.split("|"))
-    print(t)
+    logging.info(t)
-def run_config(conf_file_path):
+def run_config(log_level, conf_file_path):
    try:
        from pimdm import Config
        pim_globals.MULTICAST_TABLE_ID, pim_globals.UNICAST_TABLE_ID = Config.get_vrfs(conf_file_path)
@@ -184,6 +233,7 @@ def main():
    """
    Entry point for PIM-DM
    """
+    log_level = logging.INFO
    parser = args_parser()
    args = parser.parse_args()
@@ -198,18 +248,19 @@ def main():
    pim_globals.MULTICAST_TABLE_ID = args.multicast_vrf[0]
    pim_globals.UNICAST_TABLE_ID = args.unicast_vrf[0]
+    if args.verbose:
+        log_level = logging.DEBUG
    if args.start:
-        start()
+        start(log_level)
    elif args.stop:
        client_socket(args)
    elif args.config:
-        run_config(os.path.abspath(args.config[0]))
+        run_config(log_level, os.path.abspath(args.config[0]))
-    elif args.verbose:
-        os.system("tail -f {}".format(PROCESS_LOG_STDOUT_FILE.format(pim_globals.MULTICAST_TABLE_ID)))
    elif args.multicast_routes:
        print_multicast_routes(args)
    elif not is_running():
-        print("PIM-DM is not running")
+        logging.error("PIM-DM is not running")
        parser.print_usage()
    client_socket(args)
@@ -220,6 +271,23 @@ def process_file_path():
 def process_socket_path():
    return PROCESS_SOCKET.format(pim_globals.MULTICAST_TABLE_ID)
+def configure_logging(log_level):
+    os.makedirs(PROCESS_LOG_FOLDER, exist_ok=True)
+    os.chdir(PROCESS_LOG_FOLDER)
+    log_file = PROCESS_LOG_STDOUT_FILE.format(pim_globals.MULTICAST_TABLE_ID)
+    config = LOG_CONFIG.copy()
+    config['handlers']['console']['level'] = log_level
+    config['handlers']['file']['filename'] = log_file
+    config['handlers']['file']['level'] = log_level
+    config['handlers']['errors']['filename'] = PROCESS_LOG_STDERR_FILE.format(pim_globals.MULTICAST_TABLE_ID)
+    config['handlers']['console_detailed']['level'] = log_level
+    config['handlers']['file_detailed']['filename'] = log_file
+    config['handlers']['file_detailed']['level'] = log_level
+    config['root']['level'] = log_level
+    logging.config.dictConfig(config)
 def get_server_address():
    server_address = process_socket_path()
@@ -233,11 +301,11 @@ def exit_main(cleanup):
    while cleanup:
        try:
            cleanup.pop()()
-        except Exception:
+        except Exception as e:
-            traceback.print_exc()
+            logging.error(e, exc_info=True)
    exit.release()
-def start(conf_file_path=None):
+def start(log_level, conf_file_path=None):
    exit.signal(0, signal.SIGINT, signal.SIGTERM)
    process_file = process_file_path()
@@ -250,23 +318,11 @@ def start(conf_file_path=None):
        os.makedirs(PROCESS_DIRECTORY, exist_ok=True)
        os.mknod(process_file)
-        os.makedirs(PROCESS_LOG_FOLDER, exist_ok=True)
+        configure_logging(log_level)
-        os.chdir(PROCESS_LOG_FOLDER)
-        os.umask(0)
-        # redirect standard file descriptors
-        sys.stdout.flush()
+        os.umask(0)
-        sys.stderr.flush()
-        so = open(PROCESS_LOG_STDOUT_FILE.format(pim_globals.MULTICAST_TABLE_ID), 'a+')
-        cleanup.append(so.close)
-        se = open(PROCESS_LOG_STDERR_FILE.format(pim_globals.MULTICAST_TABLE_ID), 'a+')
-        cleanup.append(se.close)
-        os.dup2(so.fileno(), sys.stdout.fileno())
-        os.dup2(se.fileno(), sys.stderr.fileno())
-        print("start")
+        logging.info("start")
        cleanup.insert(0, Main.stop)
        Main.main()
        if conf_file_path:

--- a/pimdm/UnicastRouting.py
+++ b/pimdm/UnicastRouting.py
 import socket
 import ipaddress
+import logging
 from threading import RLock
 from socket import if_indextoname
 from pyroute2 import IPDB
@@ -64,9 +65,9 @@ class UnicastRouting(object):
            for mask_len in range(full_mask, 0, -1):
                dst_network = str(ipaddress.ip_interface(ip_dst + "/" + str(mask_len)).network)
-                print(dst_network)
+                logging.debug(dst_network)
                if dst_network in ipdb.routes.tables[pim_globals.UNICAST_TABLE_ID]:
-                    print(info)
+                    logging.debug(info)
                    if ipdb.routes[{'dst': dst_network, 'family': family,
                                    'table': pim_globals.UNICAST_TABLE_ID}]['ipdb_scope'] != 'gc':
                        info = ipdb.routes[{'dst': dst_network, 'family': family, 'table': pim_globals.UNICAST_TABLE_ID}]
@@ -74,10 +75,10 @@ class UnicastRouting(object):
                else:
                    continue
            if not info:
-                print("0.0.0.0/0 or ::/0")
+                logging.debug("0.0.0.0/0 or ::/0")
                if "default" in ipdb.routes.tables[pim_globals.UNICAST_TABLE_ID]:
                    info = ipdb.routes[{'dst': 'default', 'family': family, 'table': pim_globals.UNICAST_TABLE_ID}]
-            print(info)
+            logging.debug(info)
            return info
    @staticmethod
@@ -130,18 +131,18 @@ class UnicastRouting(object):
        Kernel notified about a change
        Verify the type of change and recheck all trees if necessary
        """
-        print("unicast change?")
+        logging.debug("unicast change?")
-        print(action)
+        logging.debug(action)
        UnicastRouting.lock.acquire()
        family = msg['family']
        if action == "RTM_NEWROUTE" or action == "RTM_DELROUTE":
-            print(ipdb.routes)
+            logging.debug(ipdb.routes)
            mask_len = msg["dst_len"]
            network_address = None
            attrs = msg["attrs"]
-            print(attrs)
+            logging.debug(attrs)
            for (key, value) in attrs:
-                print((key, value))
+                logging.debug((key, value))
                if key == "RTA_DST":
                    network_address = value
                    break
@@ -149,11 +150,11 @@ class UnicastRouting(object):
                network_address = "0.0.0.0"
            elif network_address is None and family == socket.AF_INET6:
                network_address = "::"
-            print(network_address)
+            logging.debug(network_address)
-            print(mask_len)
+            logging.debug(mask_len)
-            print(network_address + "/" + str(mask_len))
+            logging.debug(network_address + "/" + str(mask_len))
            subnet = ipaddress.ip_network(network_address + "/" + str(mask_len))
-            print(str(subnet))
+            logging.debug(str(subnet))
            UnicastRouting.lock.release()
            from pimdm import Main
            if family == socket.AF_INET:

--- a/pimdm/packet/PacketIpHeader.py
+++ b/pimdm/packet/PacketIpHeader.py
 import struct
 import socket
+import logging
 class PacketIpHeader:
@@ -24,7 +25,7 @@ class PacketIpHeader:
    def parse_bytes(data: bytes):
        (verhlen, ) = struct.unpack(PacketIpHeader.IP_HDR, data[:PacketIpHeader.IP_HDR_LEN])
        ver = (verhlen & 0xF0) >> 4
-        print("ver:", ver)
+        logging.debug("ver:%s", ver)
        return PACKET_HEADER.get(ver).parse_bytes(data)

--- a/pimdm/packet/PacketPimEncodedGroupAddress.py
+++ b/pimdm/packet/PacketPimEncodedGroupAddress.py
 import ipaddress
 import struct
 import socket
+import logging
 '''
 0                   1                   2                   3
 0 1 2 3 4 5 6 7 8 9 0 1 2 3 4 5 6 7 8 9 0 1 2 3 4 5 6 7 8 9 0 1
@@ -82,7 +83,7 @@ class PacketPimEncodedGroupAddress:
            raise Exception("Unknown address family")
        if encoding != 0:
-            print("unknown encoding")
+            logging.error("unknown encoding")
            raise Exception
        return PacketPimEncodedGroupAddress(ip, mask_len)
--- a/pimdm/packet/PacketPimEncodedSourceAddress.py
+++ b/pimdm/packet/PacketPimEncodedSourceAddress.py
 import ipaddress
 import struct
 import socket
+import logging
 '''
 0                   1                   2                   3
 0 1 2 3 4 5 6 7 8 9 0 1 2 3 4 5 6 7 8 9 0 1 2 3 4 5 6 7 8 9 0 1
@@ -84,7 +85,7 @@ class PacketPimEncodedSourceAddress:
            raise Exception("Unknown address family")
        if encoding != 0:
-            print("unknown encoding")
+            logging.error("unknown encoding")
            raise Exception
        return PacketPimEncodedSourceAddress(ip, mask_len)
--- a/pimdm/packet/PacketPimEncodedUnicastAddress.py
+++ b/pimdm/packet/PacketPimEncodedUnicastAddress.py
 import ipaddress
 import struct
 import socket
+import logging
 '''
 0                   1                   2                   3
 0 1 2 3 4 5 6 7 8 9 0 1 2 3 4 5 6 7 8 9 0 1 2 3 4 5 6 7 8 9 0 1
@@ -73,7 +74,7 @@ class PacketPimEncodedUnicastAddress:
            raise Exception("Unknown address family")
        if encoding != 0:
-            print("unknown encoding")
+            logging.error("unknown encoding")
            raise Exception
        return PacketPimEncodedUnicastAddress(ip)
--- a/pimdm/packet/PacketPimHeader.py
+++ b/pimdm/packet/PacketPimHeader.py
+import logging
 import struct
 from .PacketPimHello import PacketPimHello
@@ -51,24 +52,24 @@ class PacketPimHeader(PacketPayload):
    @staticmethod
    def parse_bytes(data: bytes):
-        print("parsePimHdr: ", data)
+        logging.debug("parsePimHdr: %s", data)
        pim_hdr = data[0:PacketPimHeader.PIM_HDR_LEN]
        (pim_ver_type, reserved, rcv_checksum) = struct.unpack(PacketPimHeader.PIM_HDR, pim_hdr)
-        print(pim_ver_type, reserved, rcv_checksum)
+        logging.debug("%s %s %s", pim_ver_type, reserved, rcv_checksum)
        pim_version = (pim_ver_type & 0xF0) >> 4
        pim_type = pim_ver_type & 0x0F
        if pim_version != PacketPimHeader.PIM_VERSION:
-            print("Version of PIM packet received not known (!=2)")
+            logging.error("Version of PIM packet received not known (!=2)")
            raise Exception
        msg_to_checksum = data[0:2] + b'\x00\x00' + data[4:]
        if checksum(msg_to_checksum) != rcv_checksum:
-            print("wrong checksum")
+            logging.error("wrong checksum")
-            print("checksum calculated: " + str(checksum(msg_to_checksum)))
+            logging.error("checksum calculated: %s", checksum(msg_to_checksum))
-            print("checksum recv: " + str(rcv_checksum))
+            logging.error("checksum recv: %s", rcv_checksum)
            raise Exception
        pim_payload = data[PacketPimHeader.PIM_HDR_LEN:]

--- a/pimdm/tree/KernelEntry.py
+++ b/pimdm/tree/KernelEntry.py
@@ -48,15 +48,13 @@ class KernelEntry:
                        self.interface_state[i] = TreeInterfaceUpstream(self, i)
                    else:
                        self.interface_state[i] = TreeInterfaceDownstream(self, i)
-                except:
+                except Exception as e:
-                    import traceback
+                    logging.error(e, exc_info=True)
-                    print(traceback.print_exc())
-                    continue
        self.change()
        self.evaluate_olist_change()
        self.timestamp_of_last_state_refresh_message_received = 0
-        print('Tree created')
+        logging.debug('Tree created')
    def get_inbound_interface_index(self):
        """
@@ -77,14 +75,14 @@ class KernelEntry:
        """
        Receive data packet regarding this tree in interface with VIF index
        """
-        print("recv data")
+        logging.debug("recv data")
        self.interface_state[index].recv_data_msg()
    def recv_assert_msg(self, index, packet):
        """
        Receive assert packet regarding this tree in interface with VIF index
        """
-        print("recv assert")
+        logging.debug("recv assert")
        pkt_assert = packet.payload.payload
        metric = pkt_assert.metric
        metric_preference = pkt_assert.metric_preference
@@ -97,7 +95,7 @@ class KernelEntry:
        """
        Receive Prune packet regarding this tree in interface with VIF index
        """
-        print("recv prune msg")
+        logging.debug("recv prune msg")
        holdtime = packet.payload.payload.hold_time
        upstream_neighbor_address = packet.payload.payload.upstream_neighbor_address
        self.interface_state[index].recv_prune_msg(upstream_neighbor_address=upstream_neighbor_address, holdtime=holdtime)
@@ -106,7 +104,7 @@ class KernelEntry:
        """
        Receive Join packet regarding this tree in interface with VIF index
        """
-        print("recv join msg")
+        logging.debug("recv join msg")
        upstream_neighbor_address = packet.payload.payload.upstream_neighbor_address
        self.interface_state[index].recv_join_msg(upstream_neighbor_address)
@@ -114,7 +112,7 @@ class KernelEntry:
        """
        Receive Graft packet regarding this tree in interface with VIF index
        """
-        print("recv graft msg")
+        logging.debug("recv graft msg")
        upstream_neighbor_address = packet.payload.payload.upstream_neighbor_address
        source_ip = packet.ip_header.ip_src
        self.interface_state[index].recv_graft_msg(upstream_neighbor_address, source_ip)
@@ -123,7 +121,7 @@ class KernelEntry:
        """
        Receive GraftAck packet regarding this tree in interface with VIF index
        """
-        print("recv graft ack msg")
+        logging.debug("recv graft ack msg")
        source_ip = packet.ip_header.ip_src
        self.interface_state[index].recv_graft_ack_msg(source_ip)
@@ -131,7 +129,7 @@ class KernelEntry:
        """
        Receive StateRefresh packet regarding this tree in interface with VIF index
        """
-        print("recv state refresh msg")
+        logging.debug("recv state refresh msg")
        source_of_state_refresh = packet.ip_header.ip_src
        metric_preference = packet.payload.payload.metric_preference

--- a/pimdm/tree/data_packets_socket.py
+++ b/pimdm/tree/data_packets_socket.py
 import struct
 import socket
 import ipaddress
+import logging
 from ctypes import create_string_buffer, addressof
 from pcap_wrapper import bpf
@@ -25,7 +26,7 @@ def get_s_g_bpf_filter_code(source, group, interface_name):
        raise Exception("Unknown IP family")
    num, bpf_filter = bpf(bpf_filter_str.encode()).compiled_filter()
-    print(num)
+    logging.debug(num)
    # defined in linux/filter.h.
    b = create_string_buffer(bpf_filter)

--- a/pimdm/tree/tree_if_downstream.py
+++ b/pimdm/tree/tree_if_downstream.py
@@ -6,7 +6,6 @@ from .tree_interface import TreeInterface
 from pimdm.packet.PacketPimStateRefresh import PacketPimStateRefresh
 from pimdm.packet.Packet import Packet
 from pimdm.packet.PacketPimHeader import PacketPimHeader
-import traceback
 import logging
@@ -103,7 +102,7 @@ class TreeInterfaceDownstream(TreeInterface):
    # Override
    def recv_graft_msg(self, upstream_neighbor_address, source_ip):
-        print("GRAFT!!!")
+        logging.debug("GRAFT!!!")
        super().recv_graft_msg(upstream_neighbor_address, source_ip)
        if upstream_neighbor_address == self.get_ip():
@@ -114,7 +113,7 @@ class TreeInterfaceDownstream(TreeInterface):
    # Send messages
    ######################################
    def send_state_refresh(self, state_refresh_msg_received):
-        print("send state refresh")
+        logging.debug("send state refresh")
        if state_refresh_msg_received is None:
            return
@@ -151,9 +150,8 @@ class TreeInterfaceDownstream(TreeInterface):
            pckt = Packet(payload=PacketPimHeader(ph))
            self.get_interface().send(pckt.bytes())
-        except:
+        except Exception as e:
-            traceback.print_exc()
+            logging.error(e, exc_info=True)
-            return
    ##########################################################

--- a/pimdm/tree/tree_if_upstream.py
+++ b/pimdm/tree/tree_if_upstream.py
@@ -7,7 +7,6 @@ import random
 from .metric import AssertMetric
 from .originator import OriginatorState, OriginatorStateABC
 from pimdm.packet.PacketPimStateRefresh import PacketPimStateRefresh
-import traceback
 from . import data_packets_socket
 import threading
 import logging
@@ -63,11 +62,10 @@ class TreeInterfaceUpstream(TreeInterface):
        while self.socket_is_enabled:
            try:
                self.socket_pkt.recvfrom(0)
-                print("DATA RECEIVED")
+                logging.debug("DATA RECEIVED")
                self.recv_data_msg()
-            except:
+            except Exception as e:
-                traceback.print_exc()
+                logging.error(e, exc_info=True)
-                continue
    ##########################################
    # Set state
@@ -191,7 +189,7 @@ class TreeInterfaceUpstream(TreeInterface):
        self._graft_prune_state.seePrune(self)
    def recv_graft_ack_msg(self, source_ip_of_graft_ack):
-        print("GRAFT ACK!!!")
+        logging.debug("GRAFT ACK!!!")
        if source_ip_of_graft_ack == self.get_neighbor_RPF():
            self._graft_prune_state.recvGraftAckFromRPFnbr(self)

--- a/pimdm/tree/tree_interface.py
+++ b/pimdm/tree/tree_interface.py
 from abc import ABCMeta, abstractmethod
 from threading import RLock
-import traceback
 from .downstream_prune import DownstreamState
 from .assert_state import AssertState, AssertStateABC
@@ -78,8 +77,8 @@ class TreeInterface(metaclass=ABCMeta):
                    old_neighbor.unsubscribe_nlt_expiration(self)
                if new_neighbor is not None:
                    new_neighbor.subscribe_nlt_expiration(self)
-            except:
+            except Exception as e:
-                traceback.print_exc()
+                logging.error(e, exc_info=True)
            finally:
                self._assert_winner_metric = new_assert_metric
@@ -139,7 +138,7 @@ class TreeInterface(metaclass=ABCMeta):
    # Send messages
    ######################################
    def send_graft(self):
-        print("send graft")
+        logging.debug("send graft")
        try:
            (source, group) = self.get_tree_id()
@@ -148,12 +147,11 @@ class TreeInterface(metaclass=ABCMeta):
            ph.add_multicast_group(PacketPimJoinPruneMulticastGroup(group,  joined_src_addresses=[source]))
            pckt = Packet(payload=PacketPimHeader(ph))
            self.get_interface().send(pckt.bytes(), ip_dst)
-        except:
+        except Exception as e:
-            traceback.print_exc()
+            logging.error(e, exc_info=True)
-            return
    def send_graft_ack(self, ip_sender):
-        print("send graft ack")
+        logging.debug("send graft ack")
        try:
            (source, group) = self.get_tree_id()
@@ -161,15 +159,14 @@ class TreeInterface(metaclass=ABCMeta):
            ph.add_multicast_group(PacketPimJoinPruneMulticastGroup(group,  joined_src_addresses=[source]))
            pckt = Packet(payload=PacketPimHeader(ph))
            self.get_interface().send(pckt.bytes(), ip_sender)
-        except:
+        except Exception as e:
-            traceback.print_exc()
+            logging.error(e, exc_info=True)
-            return
    def send_prune(self, holdtime=None):
        if holdtime is None:
            holdtime = T_LIMIT
-        print("send prune")
+        logging.debug("send prune")
        try:
            (source, group) = self.get_tree_id()
            ph = PacketPimJoinPrune(self.get_neighbor_RPF(), holdtime)
@@ -177,10 +174,9 @@ class TreeInterface(metaclass=ABCMeta):
            pckt = Packet(payload=PacketPimHeader(ph))
            self.get_interface().send(pckt.bytes())
-            print('sent prune msg')
+            logging.debug('sent prune msg')
-        except:
+        except Exception as e:
-            traceback.print_exc()
+            logging.error(e, exc_info=True)
-            return
    def send_pruneecho(self):
        holdtime = T_LIMIT
@@ -191,13 +187,12 @@ class TreeInterface(metaclass=ABCMeta):
            pckt = Packet(payload=PacketPimHeader(ph))
            self.get_interface().send(pckt.bytes())
-            print("send prune echo")
+            logging.debug("send prune echo")
-        except:
+        except Exception as e:
-            traceback.print_exc()
+            logging.error(e, exc_info=True)
-            return
    def send_join(self):
-        print("send join")
+        logging.debug("send join")
        try:
            (source, group) = self.get_tree_id()
@@ -206,12 +201,11 @@ class TreeInterface(metaclass=ABCMeta):
            pckt = Packet(payload=PacketPimHeader(ph))
            self.get_interface().send(pckt.bytes())
-        except:
+        except Exception as e:
-            traceback.print_exc()
+            logging.error(e, exc_info=True)
-            return
    def send_assert(self):
-        print("send assert")
+        logging.debug("send assert")
        try:
            (source, group) = self.get_tree_id()
@@ -220,12 +214,11 @@ class TreeInterface(metaclass=ABCMeta):
            pckt = Packet(payload=PacketPimHeader(ph))
            self.get_interface().send(pckt.bytes())
-        except:
+        except Exception as e:
-            traceback.print_exc()
+            logging.error(e, exc_info=True)
-            return
    def send_assert_cancel(self):
-        print("send assert cancel")
+        logging.debug("send assert cancel")
        try:
            (source, group) = self.get_tree_id()
@@ -233,9 +226,8 @@ class TreeInterface(metaclass=ABCMeta):
            pckt = Packet(payload=PacketPimHeader(ph))
            self.get_interface().send(pckt.bytes())
-        except:
+        except Exception as e:
-            traceback.print_exc()
+            logging.error(e, exc_info=True)
-            return
    def send_state_refresh(self, state_refresh_msg_received: PacketPimStateRefresh):
        pass
@@ -279,7 +271,7 @@ class TreeInterface(metaclass=ABCMeta):
        self._assert_winner_metric = None
        self.clear_assert_timer()
-        print('Tree Interface deleted')
+        logging.debug('Tree Interface deleted')
    def is_olist_null(self):
        return self._kernel_entry.is_olist_null()