log igmp and neighbor events

InterfaceIGMP.py

 import socket
 import struct
+from ipaddress import IPv4Address
+from ctypes import create_string_buffer, addressof
 import netifaces
 from Packet.ReceivedPacket import ReceivedPacket
 from Interface import Interface
-from ctypes import create_string_buffer, addressof
-from ipaddress import IPv4Address
 from utils import Version_1_Membership_Report, Version_2_Membership_Report, Leave_Group, Membership_Query
-import subprocess
 if not hasattr(socket, 'SO_BINDTODEVICE'):
     socket.SO_BINDTODEVICE = 25
 
@@ -24,7 +23,7 @@ class InterfaceIGMP(Interface):
         struct.pack('HBBI', 0x6, 0, 0, 0x00000000),
     ]
 
-    def __init__(self, interface_name: str, vif_index:int):
+    def __init__(self, interface_name: str, vif_index: int):
         # SEND SOCKET
         snd_s = socket.socket(socket.AF_INET, socket.SOCK_RAW, socket.IPPROTO_IGMP)
 
@@ -104,3 +103,8 @@ class InterfaceIGMP(Interface):
         Leave_Group: receive_leave_group,
         Membership_Query: receive_membership_query,
     }
+
+    ##################
+    def remove(self):
+        super().remove()
+        self.interface_state.remove()

InterfacePIM.py

@@ -13,6 +13,7 @@ from threading import Timer
 from tree.globals import REFRESH_INTERVAL
 import socket
 import netifaces
+import logging
 
 
 class InterfacePim(Interface):
@@ -20,9 +21,10 @@ class InterfacePim(Interface):
     PROPAGATION_DELAY = 0.5
     OVERRIDE_INTERNAL = 2.5
 
-    HELLO_PERIOD = 16
+    HELLO_PERIOD = 30
     TRIGGERED_HELLO_PERIOD = 5
 
+    LOGGER = logging.getLogger('pim.Interface')
 
     def __init__(self, interface_name: str, vif_index:int, state_refresh_capable:bool=False):
         # generation id
@@ -49,6 +51,7 @@ 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})
 
         # SOCKET
         ip_interface = netifaces.ifaddresses(interface_name)[netifaces.AF_INET][0]['addr']
@@ -103,6 +106,7 @@ class InterfacePim(Interface):
         self.hello_timer.start()
 
     def send_hello(self):
+        self.interface_logger.debug('Send Hello message')
         self.hello_timer.cancel()
 
         pim_payload = PacketPimHello()
@@ -170,6 +174,7 @@ class InterfacePim(Interface):
     def remove_neighbor(self, ip):
         with self.neighbors_lock.genWlock():
             del self.neighbors[ip]
+            self.interface_logger.debug("Remove neighbor: " + ip)
             self.check_number_of_neighbors()
 
 

Neighbor.py

@@ -3,14 +3,25 @@ import time
 from utils import HELLO_HOLD_TIME_NO_TIMEOUT, HELLO_HOLD_TIME_TIMEOUT, TYPE_CHECKING
 from threading import Lock, RLock
 import Main
+import logging
 if TYPE_CHECKING:
     from InterfacePIM import InterfacePim
 
 
 class Neighbor:
-    def __init__(self, contact_interface: "InterfacePim", ip, generation_id: int, hello_hold_time: int, state_refresh_capable:bool):
+    LOGGER = logging.getLogger('pim.Interface.Neighbor')
+
+
+    def __init__(self, contact_interface: "InterfacePim", ip, generation_id: int, hello_hold_time: int,
+                 state_refresh_capable: bool):
         if hello_hold_time == HELLO_HOLD_TIME_TIMEOUT:
             raise Exception
+        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) +
+                                   '; HelloHoldTime: ' + str(hello_hold_time) + '; StateRefreshCapable: ' +
+                                   str(state_refresh_capable))
         self.contact_interface = contact_interface
         self.ip = ip
         self.generation_id = generation_id
@@ -35,7 +46,9 @@ class Neighbor:
 
         if hello_hold_time == HELLO_HOLD_TIME_TIMEOUT:
             self.remove()
+            self.neighbor_logger.debug('Detected neighbor removal of ' + self.ip)
         elif hello_hold_time != HELLO_HOLD_TIME_NO_TIMEOUT:
+            self.neighbor_logger.debug('Neighbor Liveness Timer reseted of ' + self.ip)
             self.neighbor_liveness_timer = Timer(hello_hold_time, self.remove)
             self.neighbor_liveness_timer.start()
         else:
@@ -44,6 +57,7 @@ class Neighbor:
     def set_generation_id(self, generation_id):
         # neighbor restarted
         if self.generation_id != generation_id:
+            self.neighbor_logger.debug('Detected reset of ' + self.ip + '... new GenerationID: ' + str(generation_id))
             self.generation_id = generation_id
             self.contact_interface.force_send_hello()
             self.reset()
@@ -64,7 +78,7 @@ class Neighbor:
         print('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)
         self.contact_interface.remove_neighbor(self.ip)
 
         # notify interfaces which have this neighbor as AssertWinner
@@ -78,6 +92,9 @@ class Neighbor:
 
 
     def receive_hello(self, generation_id, hello_hold_time, state_refresh_capable):
+        self.neighbor_logger.debug('Receive Hello message with HelloHoldTime: ' + str(hello_hold_time) +
+                                   '; GenerationID: ' + str(generation_id) + '; StateRefreshCapable: ' +
+                                   str(state_refresh_capable) + ' from neighbor ' + self.ip)
         if hello_hold_time == HELLO_HOLD_TIME_TIMEOUT:
             self.set_hello_hold_time(hello_hold_time)
         else:
@@ -87,7 +104,6 @@ class Neighbor:
         if state_refresh_capable != self.state_refresh_capable:
             self.state_refresh_capable = state_refresh_capable
 
-
     def subscribe_nlt_expiration(self, tree_if):
         with self.tree_interface_nlt_subscribers_lock:
             if tree_if not in self.tree_interface_nlt_subscribers:

TestLogger.py

@@ -7,7 +7,7 @@ class RootFilter(logging.Filter):
     Rather than use actual contextual information, we just use random
     data in this demo.
     """
-    def __init__(self, router_name, tree=''):
+    def __init__(self, router_name):
         super().__init__()
         self.router_name = router_name
 
@@ -19,4 +19,6 @@ class RootFilter(logging.Filter):
             record.vif = ''
         if not hasattr(record, 'interfacename'):
             record.interfacename = ''
+        if not hasattr(record, 'neighbor_ip'):
+            record.neighbor_ip = ''
         return True

igmp/GroupState.py

+import logging
+from threading import Lock
 from threading import Timer
-from .wrapper import NoMembersPresent
+
 from utils import GroupMembershipInterval, LastMemberQueryInterval, TYPE_CHECKING
-from threading import Lock
+from .wrapper import NoMembersPresent
 
 if TYPE_CHECKING:
     from .RouterState import RouterState
 
 
 class GroupState(object):
+    LOGGER = logging.getLogger('pim.igmp.RouterState.GroupState')
+
     def __init__(self, router_state: 'RouterState', group_ip: str):
+        #logger
+        extra_dict_logger = router_state.router_state_logger.extra.copy()
+        extra_dict_logger['tree'] = '(*,' + group_ip + ')'
+        self.group_state_logger = logging.LoggerAdapter(GroupState.LOGGER, extra_dict_logger)
+
+        #timers and state
         self.router_state = router_state
         self.group_ip = group_ip
         self.state = NoMembersPresent
@@ -25,6 +35,13 @@ class GroupState(object):
     def print_state(self):
         return self.state.print_state()
 
+    ###########################################
+    # Set state
+    ###########################################
+    def set_state(self, state):
+        self.state = state
+        self.group_state_logger.debug("change membership state to: " + state.print_state())
+
     ###########################################
     # Set timers
     ###########################################
@@ -130,3 +147,12 @@ class GroupState(object):
 
     def has_members(self):
         return self.state is not NoMembersPresent
+
+    def remove(self):
+        with self.multicast_interface_state_lock:
+            self.clear_retransmit_timer()
+            self.clear_timer()
+            self.clear_v1_host_timer()
+            for interface_state in self.multicast_interface_state:
+                interface_state.notify_igmp(has_members=False)
+            del self.multicast_interface_state[:]

igmp/RouterState.py

+from threading import Timer
+import logging
+
 from Packet.PacketIGMPHeader import PacketIGMPHeader
 from Packet.ReceivedPacket import ReceivedPacket
-from threading import Timer
 from utils import Membership_Query, QueryResponseInterval, QueryInterval, OtherQuerierPresentInterval, TYPE_CHECKING
+from RWLock.RWLock import RWLockWrite
 from .querier.Querier import Querier
 from .nonquerier.NonQuerier import NonQuerier
 from .GroupState import GroupState
-from RWLock.RWLock import RWLockWrite
 
 if TYPE_CHECKING:
     from InterfaceIGMP import InterfaceIGMP
 
 
 class RouterState(object):
+    ROUTER_STATE_LOGGER = logging.getLogger('pim.igmp.RouterState')
+
     def __init__(self, interface: 'InterfaceIGMP'):
+        #logger
+        logger_extra = dict()
+        logger_extra['vif'] = interface.vif_index
+        logger_extra['interfacename'] = interface.interface_name
+        self.router_state_logger = logging.LoggerAdapter(RouterState.ROUTER_STATE_LOGGER, logger_extra)
+
         # interface of the router connected to the network
         self.interface = interface
 
@@ -75,8 +85,10 @@ class RouterState(object):
     def change_interface_state(self, querier: bool):
         if querier:
             self.interface_state = Querier
+            self.router_state_logger.debug('change querier state to -> Querier')
         else:
             self.interface_state = NonQuerier
+            self.router_state_logger.debug('change querier state to -> NonQuerier')
 
     ############################################
     # group state methods
@@ -125,4 +137,8 @@ class RouterState(object):
         #if igmp_group != "0.0.0.0":
             max_response_time = packet.payload.max_resp_time
             #self.group_state[igmp_group].receive_group_specific_query(max_response_time)
-            self.get_group_state(igmp_group).receive_group_specific_query(max_response_time)
+            self.get_group_state(igmp_group).receive_group_specific_query(max_response_time)
\ No newline at end of file
+
+    def remove(self):
+        for group in self.group_state.values():
+            group.remove()
\ No newline at end of file

igmp/nonquerier/CheckingMembership.py

+from utils import TYPE_CHECKING
 from ..wrapper import NoMembersPresent
 from ..wrapper import MembersPresent
-from utils import TYPE_CHECKING
 
 if TYPE_CHECKING:
     from ..GroupState import GroupState
 
 
 def group_membership_timeout(group_state: 'GroupState'):
-    group_state.state = NoMembersPresent
+    group_state.group_state_logger.debug('NonQuerier CheckingMembership: group_membership_timeout')
+    group_state.set_state(NoMembersPresent)
 
     # NOTIFY ROUTING - !!!!
     group_state.notify_routing_remove()
 
+
 def group_membership_v1_timeout(group_state: 'GroupState'):
+    group_state.group_state_logger.debug('NonQuerier CheckingMembership: group_membership_v1_timeout')
     # do nothing
     return
 
 
 def retransmit_timeout(group_state: 'GroupState'):
+    group_state.group_state_logger.debug('NonQuerier CheckingMembership: retransmit_timeout')
     # do nothing
     return
 
 
 def receive_v1_membership_report(group_state: 'GroupState'):
+    group_state.group_state_logger.debug('NonQuerier CheckingMembership: receive_v1_membership_report')
     receive_v2_membership_report(group_state)
 
 
 def receive_v2_membership_report(group_state: 'GroupState'):
+    group_state.group_state_logger.debug('NonQuerier CheckingMembership: receive_v2_membership_report')
     group_state.set_timer()
-    group_state.state = MembersPresent
+    group_state.set_state(MembersPresent)
 
 
 def receive_leave_group(group_state: 'GroupState'):
+    group_state.group_state_logger.debug('NonQuerier CheckingMembership: receive_leave_group')
     # do nothing
     return
 
 
 def receive_group_specific_query(group_state: 'GroupState', max_response_time: int):
+    group_state.group_state_logger.debug('NonQuerier CheckingMembership: receive_group_specific_query')
     # do nothing
     return

igmp/nonquerier/MembersPresent.py

+from utils import TYPE_CHECKING
 from ..wrapper import NoMembersPresent
 from ..wrapper import CheckingMembership
-from utils import TYPE_CHECKING
 
 if TYPE_CHECKING:
     from ..GroupState import GroupState
 
 
 def group_membership_timeout(group_state: 'GroupState'):
-    group_state.state = NoMembersPresent
+    group_state.group_state_logger.debug('NonQuerier MembersPresent: group_membership_timeout')
+    group_state.set_state(NoMembersPresent)
 
     # NOTIFY ROUTING - !!!!
     group_state.notify_routing_remove()
 
 
 def group_membership_v1_timeout(group_state: 'GroupState'):
+    group_state.group_state_logger.debug('NonQuerier MembersPresent: group_membership_v1_timeout')
     # do nothing
     return
 
 
 def retransmit_timeout(group_state: 'GroupState'):
+    group_state.group_state_logger.debug('NonQuerier MembersPresent: retransmit_timeout')
     # do nothing
     return
 
 
 def receive_v1_membership_report(group_state: 'GroupState'):
+    group_state.group_state_logger.debug('NonQuerier MembersPresent: receive_v1_membership_report')
     receive_v2_membership_report(group_state)
 
 
 def receive_v2_membership_report(group_state: 'GroupState'):
+    group_state.group_state_logger.debug('NonQuerier MembersPresent: receive_v2_membership_report')
     group_state.set_timer()
 
 
 def receive_leave_group(group_state: 'GroupState'):
+    group_state.group_state_logger.debug('NonQuerier MembersPresent: receive_leave_group')
     # do nothing
     return
 
 
 def receive_group_specific_query(group_state: 'GroupState', max_response_time: int):
+    group_state.group_state_logger.debug('NonQuerier MembersPresent: receive_group_specific_query')
     group_state.set_timer(alternative=True, max_response_time=max_response_time)
-    group_state.state = CheckingMembership
+    group_state.set_state(CheckingMembership)

igmp/nonquerier/NoMembersPresent.py

-from ..wrapper import MembersPresent
 from utils import TYPE_CHECKING
+from ..wrapper import MembersPresent
 
 if TYPE_CHECKING:
     from ..GroupState import GroupState
 
 
 def group_membership_timeout(group_state: 'GroupState'):
+    group_state.group_state_logger.debug('NonQuerier NoMembersPresent: group_membership_timeout')
     # do nothing
     return
 
 
 def group_membership_v1_timeout(group_state: 'GroupState'):
+    group_state.group_state_logger.debug('NonQuerier NoMembersPresent: group_membership_v1_timeout')
     # do nothing
     return
 
 
 def retransmit_timeout(group_state: 'GroupState'):
+    group_state.group_state_logger.debug('NonQuerier NoMembersPresent: retransmit_timeout')
     # do nothing
     return
 
 
 def receive_v1_membership_report(group_state: 'GroupState'):
+    group_state.group_state_logger.debug('NonQuerier NoMembersPresent: receive_v1_membership_report')
     receive_v2_membership_report(group_state)
 
 
 def receive_v2_membership_report(group_state: 'GroupState'):
+    group_state.group_state_logger.debug('NonQuerier NoMembersPresent: receive_v2_membership_report')
     group_state.set_timer()
-    group_state.state = MembersPresent
+    group_state.set_state(MembersPresent)
 
     # NOTIFY ROUTING + !!!!
     group_state.notify_routing_add()
 
 
 def receive_leave_group(group_state: 'GroupState'):
+    group_state.group_state_logger.debug('NonQuerier NoMembersPresent: receive_leave_group')
     # do nothing
     return
 
 
 def receive_group_specific_query(group_state: 'GroupState', max_response_time: int):
+    group_state.group_state_logger.debug('NonQuerier NoMembersPresent: receive_group_specific_query')
     # do nothing
     return

igmp/nonquerier/NonQuerier.py

+from ipaddress import IPv4Address
 from utils import Membership_Query, QueryResponseInterval, LastMemberQueryCount, TYPE_CHECKING
 from Packet.PacketIGMPHeader import PacketIGMPHeader
 from Packet.ReceivedPacket import ReceivedPacket
 from . import NoMembersPresent, MembersPresent, CheckingMembership
-from ipaddress import IPv4Address
 
 if TYPE_CHECKING:
     from ..RouterState import RouterState
@@ -12,11 +12,13 @@ class NonQuerier:
 
     @staticmethod
     def general_query_timeout(router_state: 'RouterState'):
+        router_state.router_state_logger.debug('NonQuerier state: general_query_timeout')
         # do nothing
         return
 
     @staticmethod
     def other_querier_present_timeout(router_state: 'RouterState'):
+        router_state.router_state_logger.debug('NonQuerier state: other_querier_present_timeout')
         #change state to Querier
         router_state.change_interface_state(querier=True)
 
@@ -29,6 +31,7 @@ class NonQuerier:
 
     @staticmethod
     def receive_query(router_state: 'RouterState', packet: ReceivedPacket):
+        router_state.router_state_logger.debug('NonQuerier state: receive_query')
         source_ip = packet.ip_header.ip_src
 
         # if source ip of membership query not lower than the ip of the received interface => ignore

igmp/querier/CheckingMembership.py

 from Packet.PacketIGMPHeader import PacketIGMPHeader
-from ..wrapper import NoMembersPresent, MembersPresent, Version1MembersPresent
 from utils import Membership_Query, LastMemberQueryInterval, TYPE_CHECKING
+from ..wrapper import NoMembersPresent, MembersPresent, Version1MembersPresent
 if TYPE_CHECKING:
     from ..GroupState import GroupState
 
 
 def group_membership_timeout(group_state: 'GroupState'):
+    group_state.group_state_logger.debug('Querier CheckingMembership: group_membership_timeout')
     group_state.clear_retransmit_timer()
-    group_state.state = NoMembersPresent
+    group_state.set_state(NoMembersPresent)
 
     # NOTIFY ROUTING - !!!!
     group_state.notify_routing_remove()
 
 
 def group_membership_v1_timeout(group_state: 'GroupState'):
+    group_state.group_state_logger.debug('Querier CheckingMembership: group_membership_v1_timeout')
     # do nothing
     return
 
 
 def retransmit_timeout(group_state: 'GroupState'):
+    group_state.group_state_logger.debug('Querier CheckingMembership: retransmit_timeout')
     group_addr = group_state.group_ip
     packet = PacketIGMPHeader(type=Membership_Query, max_resp_time=LastMemberQueryInterval*10, group_address=group_addr)
     group_state.router_state.send(data=packet.bytes(), address=group_addr)
@@ -27,21 +30,25 @@ def retransmit_timeout(group_state: 'GroupState'):
 
 
 def receive_v1_membership_report(group_state: 'GroupState'):
+    group_state.group_state_logger.debug('Querier CheckingMembership: receive_v1_membership_report')
     group_state.set_timer()
     group_state.set_v1_host_timer()
-    group_state.state = Version1MembersPresent
+    group_state.set_state(Version1MembersPresent)
 
 
 def receive_v2_membership_report(group_state: 'GroupState'):
+    group_state.group_state_logger.debug('Querier CheckingMembership: receive_v2_membership_report')
     group_state.set_timer()
-    group_state.state = MembersPresent
+    group_state.set_state(MembersPresent)
 
 
 def receive_leave_group(group_state: 'GroupState'):
+    group_state.group_state_logger.debug('Querier CheckingMembership: receive_leave_group')
     # do nothing
     return
 
 
 def receive_group_specific_query(group_state: 'GroupState', max_response_time: int):
+    group_state.group_state_logger.debug('Querier CheckingMembership: receive_group_specific_query')
     # do nothing
     return

igmp/querier/MembersPresent.py

 from Packet.PacketIGMPHeader import PacketIGMPHeader
-from ..wrapper import Version1MembersPresent, CheckingMembership, NoMembersPresent
 from utils import Membership_Query, LastMemberQueryInterval, TYPE_CHECKING
+from ..wrapper import Version1MembersPresent, CheckingMembership, NoMembersPresent
 if TYPE_CHECKING:
     from ..GroupState import GroupState
 
 
 def group_membership_timeout(group_state: 'GroupState'):
-    group_state.state = NoMembersPresent
+    group_state.group_state_logger.debug('Querier MembersPresent: group_membership_timeout')
+    group_state.set_state(NoMembersPresent)
 
     # NOTIFY ROUTING - !!!!
     group_state.notify_routing_remove()
 
 
 def group_membership_v1_timeout(group_state: 'GroupState'):
+    group_state.group_state_logger.debug('Querier MembersPresent: group_membership_v1_timeout')
     # do nothing
     return
 
 
 def retransmit_timeout(group_state: 'GroupState'):
+    group_state.group_state_logger.debug('Querier MembersPresent: retransmit_timeout')
     # do nothing
     return
 
 
 def receive_v1_membership_report(group_state: 'GroupState'):
+    group_state.group_state_logger.debug('Querier MembersPresent: receive_v1_membership_report')
     group_state.set_timer()
     group_state.set_v1_host_timer()
-    group_state.state = Version1MembersPresent
+    group_state.set_state(Version1MembersPresent)
 
 
 def receive_v2_membership_report(group_state: 'GroupState'):
+    group_state.group_state_logger.debug('Querier MembersPresent: receive_v2_membership_report')
     group_state.set_timer()
 
 
 def receive_leave_group(group_state: 'GroupState'):
+    group_state.group_state_logger.debug('Querier MembersPresent: receive_leave_group')
     group_ip = group_state.group_ip
 
     group_state.set_timer(alternative=True)
@@ -41,9 +47,10 @@ def receive_leave_group(group_state: 'GroupState'):
     packet = PacketIGMPHeader(type=Membership_Query, max_resp_time=LastMemberQueryInterval*10, group_address=group_ip)
     group_state.router_state.send(data=packet.bytes(), address=group_ip)
 
-    group_state.state = CheckingMembership
+    group_state.set_state(CheckingMembership)
 
 
 def receive_group_specific_query(group_state: 'GroupState', max_response_time):
+    group_state.group_state_logger.debug('Querier MembersPresent: receive_group_specific_query')
     # do nothing
     return

igmp/querier/NoMembersPresent.py

+from utils import TYPE_CHECKING
 from ..wrapper import MembersPresent
 from ..wrapper import Version1MembersPresent
-from utils import TYPE_CHECKING
 if TYPE_CHECKING:
     from ..GroupState import GroupState
 
 
 def group_membership_timeout(group_state: 'GroupState'):
+    group_state.group_state_logger.debug('Querier NoMembersPresent: group_membership_timeout')
     # do nothing
     return
 
 
 def group_membership_v1_timeout(group_state: 'GroupState'):
+    group_state.group_state_logger.debug('Querier NoMembersPresent: group_membership_v1_timeout')
     # do nothing
     return
 
 
 def retransmit_timeout(group_state: 'GroupState'):
+    group_state.group_state_logger.debug('Querier NoMembersPresent: retransmit_timeout')
     # do nothing
     return
 
 
 def receive_v1_membership_report(group_state: 'GroupState'):
+    group_state.group_state_logger.debug('Querier NoMembersPresent: receive_v1_membership_report')
     group_state.set_timer()
     group_state.set_v1_host_timer()
-    group_state.state = Version1MembersPresent
+    group_state.set_state(Version1MembersPresent)
 
     # NOTIFY ROUTING + !!!!
     group_state.notify_routing_add()
 
 
 def receive_v2_membership_report(group_state: 'GroupState'):
+    group_state.group_state_logger.debug('Querier NoMembersPresent: receive_v2_membership_report')
     group_state.set_timer()
-    group_state.state = MembersPresent
+    group_state.set_state(MembersPresent)
 
     # NOTIFY ROUTING + !!!!
     group_state.notify_routing_add()
 
 
 def receive_leave_group(group_state: 'GroupState'):
+    group_state.group_state_logger.debug('Querier NoMembersPresent: receive_leave_group')
     # do nothing
     return
 
 
 def receive_group_specific_query(group_state: 'GroupState', max_response_time: int):
+    group_state.group_state_logger.debug('Querier NoMembersPresent: receive_group_specific_query')
     # do nothing
     return

igmp/querier/Querier.py

+from ipaddress import IPv4Address
+
+from utils import TYPE_CHECKING
+from utils import Membership_Query, QueryResponseInterval, LastMemberQueryCount, LastMemberQueryInterval
+
 from Packet.PacketIGMPHeader import PacketIGMPHeader
 from Packet.ReceivedPacket import ReceivedPacket
-from utils import Membership_Query, QueryResponseInterval, LastMemberQueryCount, LastMemberQueryInterval
 from . import CheckingMembership, MembersPresent, Version1MembersPresent, NoMembersPresent
-from ipaddress import IPv4Address
-from utils import TYPE_CHECKING
 
 if TYPE_CHECKING:
     from ..RouterState import RouterState
@@ -12,6 +14,7 @@ if TYPE_CHECKING:
 class Querier:
     @staticmethod
     def general_query_timeout(router_state: 'RouterState'):
+        router_state.router_state_logger.debug('Querier state: general_query_timeout')
         # send general query
         packet = PacketIGMPHeader(type=Membership_Query, max_resp_time=QueryResponseInterval*10)
         router_state.interface.send(packet.bytes())
@@ -21,11 +24,13 @@ class Querier:
 
     @staticmethod
     def other_querier_present_timeout(router_state: 'RouterState'):
+        router_state.router_state_logger.debug('Querier state: other_querier_present_timeout')
         # do nothing
         return
 
     @staticmethod
     def receive_query(router_state: 'RouterState', packet: ReceivedPacket):
+        router_state.router_state_logger.debug('Querier state: receive_query')
         source_ip = packet.ip_header.ip_src
 
         # if source ip of membership query not lower than the ip of the received interface => ignore

igmp/querier/Version1MembersPresent.py

+from utils import TYPE_CHECKING
 from ..wrapper import NoMembersPresent
 from ..wrapper import MembersPresent
-from utils import TYPE_CHECKING
 if TYPE_CHECKING:
     from ..GroupState import GroupState
 
 
 def group_membership_timeout(group_state: 'GroupState'):
-    group_state.state = NoMembersPresent
+    group_state.group_state_logger.debug('Querier Version1MembersPresent: group_membership_timeout')
+    group_state.set_state(NoMembersPresent)
 
     # NOTIFY ROUTING - !!!!
     group_state.notify_routing_remove()
 
 
 def group_membership_v1_timeout(group_state: 'GroupState'):
-    group_state.state = MembersPresent
-
+    group_state.group_state_logger.debug('Querier Version1MembersPresent: group_membership_v1_timeout')
+    group_state.set_state(MembersPresent)
 
 def retransmit_timeout(group_state: 'GroupState'):
+    group_state.group_state_logger.debug('Querier Version1MembersPresent: retransmit_timeout')
     # do nothing
     return
 
 
 def receive_v1_membership_report(group_state: 'GroupState'):
+    group_state.group_state_logger.debug('Querier Version1MembersPresent: receive_v1_membership_report')
     group_state.set_timer()
     group_state.set_v1_host_timer()
 
 
 def receive_v2_membership_report(group_state: 'GroupState'):
+    group_state.group_state_logger.debug('Querier Version1MembersPresent: receive_v2_membership_report')
     group_state.set_timer()
 
 
 def receive_leave_group(group_state: 'GroupState'):
+    group_state.group_state_logger.debug('Querier Version1MembersPresent: receive_leave_group')
     # do nothing
     return
 
 
 def receive_group_specific_query(group_state: 'GroupState', max_response_time: int):
+    group_state.group_state_logger.debug('Querier Version1MembersPresent: receive_group_specific_query')
     # do nothing
     return

tree/KernelEntry.py

@@ -23,6 +23,7 @@ class KernelEntry:
         #next_hop = UnicastRouting.get_route(source_ip)["gateway"]
         #self.rpf_node = source_ip if next_hop is None else next_hop
 
+        '''
         next_hop = UnicastRouting.get_route(source_ip)["gateway"]
         multipaths = UnicastRouting.get_route(source_ip)["multipath"]
 
@@ -35,6 +36,21 @@ class KernelEntry:
                 break
             else:
                 self.rpf_node = m["gateway"]
+        '''
+        unicast_route = UnicastRouting.get_route(source_ip)
+        next_hop = unicast_route["gateway"]
+        multipaths = unicast_route["multipath"]
+
+        self.rpf_node = next_hop if next_hop is not None else source_ip
+        import ipaddress
+        highest_ip = ipaddress.ip_address("0.0.0.0")
+        for m in multipaths:
+            if m["gateway"] is None:
+                self.rpf_node = source_ip
+                break
+            elif ipaddress.ip_address(m["gateway"]) > highest_ip:
+                highest_ip = ipaddress.ip_address(m["gateway"])
+                self.rpf_node = m["gateway"]
 
         print("RPF_NODE:", UnicastRouting.get_route(source_ip))
         print(self.rpf_node == source_ip)
@@ -167,6 +183,7 @@ class KernelEntry:
     def network_update(self):
         # TODO TALVEZ OUTRO LOCK PARA BLOQUEAR ENTRADA DE PACOTES
         with self.CHANGE_STATE_LOCK:
+            '''
             next_hop = UnicastRouting.get_route(self.source_ip)["gateway"]
             multipaths = UnicastRouting.get_route(self.source_ip)["multipath"]
 
@@ -179,6 +196,21 @@ class KernelEntry:
                     break
                 else:
                     rpf_node = m["gateway"]
+            '''
+            unicast_route = UnicastRouting.get_route(self.source_ip)
+            next_hop = unicast_route["gateway"]
+            multipaths = unicast_route["multipath"]
+
+            rpf_node = next_hop if next_hop is not None else self.source_ip
+            import ipaddress
+            highest_ip = ipaddress.ip_address("0.0.0.0")
+            for m in multipaths:
+                if m["gateway"] is None:
+                    rpf_node = self.source_ip
+                    break
+                elif ipaddress.ip_address(m["gateway"]) > highest_ip:
+                    highest_ip = ipaddress.ip_address(m["gateway"])
+                    rpf_node = m["gateway"]
 
             print("RPF_NODE:", UnicastRouting.get_route(self.source_ip))