After upgrading Thespian 3.10.1 to 4.0.0 in all our systems we've noticed local IP address detection does not work correctly on hosts with multiple interfaces and IP addresses where some communication paths are filtered, and some not.
After some digging I think the problem is due to 089a7f2 which was shipped in 3.10.6. This commit changes the returned type of TCPTransport.getConventionAddress() from TCPv4ActorAddress to list[TCPv4ActorAddress]. The output of getConventionAddress() is passed as external argument to IPActorAddress constructor in some code paths. The constructor code does not handle list type correctly.
To demonstrate the problem let's assume the following setup with 2 hosts. The convention leader address is 192.168.14.2 and is known to convention member at startup. The expected result is convention member will select 192.168.14.3 as its own IP address, because that's the IP address on which it can establish communication with convention leader address as per local routing (both hosts are in the same 192.168.14.0/24 subnet). The expected behavior is documented in multiprocTCPBase section in here. These host have another set of interfaces with public IP addresses which can communicate with the Internet, but Thespian traffic is blocked.
/-------------------\ /-------------------\
| convention leader | | convention member |
| 192.168.14.2 | <--- 192.168.14.0/24 subnet, communication possible ---> | 192.168.14.3 |
| 94.y.y.y | <--- communication filtered ---> | 94.x.x.x |
\-------------------/ \-------------------/
With extra debug logs in IPBase.py we can see member incorrectly selects its own IP address as 94.x.x.x despite external argument being non-empty. I've marked the important log lines with <--- THIS. Note how IP address selection works fine when external is a tuple, not a list. The problem is additionally confirmed with printout of self._adminAddr from TCPTransport constructor. I've modified __str__() of IPActorAddress to not omit local IP address in such case but add * prefix instead, so ActorAddr-(T|:1900) becomes ActorAddr-(T|*94.x.x.x:1900). Also note how later in convention_setup() local address is again 94.x.x.x. The convention registration is attempted but later the process fails as communication is not possible. I've omitted that part.
2025-02-23 11:49:22.477014 p19410 dbg TCPTransport.__init__(): externalAddr = ('192.168.14.2', 1900)
2025-02-23 11:49:22.477061 p19410 dbg IPActorAddress.__init__(): on entry: baseaddr = None, external = ('192.168.14.2', 1900)
2025-02-23 11:49:22.477135 p19410 dbg IPActorAddress.__init__(): on exit: baseaddr = 192.168.14.3
2025-02-23 11:49:22.477196 p19410 dbg IPActorAddress.__init__(): on entry: baseaddr = 192.168.14.2, external = True
2025-02-23 11:49:22.477239 p19410 dbg IPActorAddress.__init__(): on exit: baseaddr = 192.168.14.2
2025-02-23 11:49:22.477286 p19410 dbg IPActorAddress.__init__(): on entry: baseaddr = None, external = [<thespian.actors.ActorAddress object at 0x7fe7042e0c50>] <--- THIS
2025-02-23 11:49:22.477349 p19410 dbg IPActorAddress.__init__(): on exit: baseaddr = 94.x.x.x <--- THIS
2025-02-23 11:49:22.477399 p19410 dbg TCPTransport.__init__(): self._adminAddr = ActorAddr-(T|*94.x.x.x:1900)
2025-02-23 11:49:22.477462 p19410 dbg IPActorAddress.__init__(): on entry: baseaddr = 192.168.14.3, external = True
2025-02-23 11:49:22.477500 p19410 dbg IPActorAddress.__init__(): on exit: baseaddr = 192.168.14.3
2025-02-23 11:49:22.477570 p19410 dbg IPActorAddress.__init__(): on entry: baseaddr = 192.168.14.2, external = True
2025-02-23 11:49:22.477607 p19410 dbg IPActorAddress.__init__(): on exit: baseaddr = 192.168.14.2
2025-02-23 11:49:22.477653 p19410 dbg IPActorAddress.__init__(): on entry: baseaddr = None, external = [<thespian.actors.ActorAddress object at 0x7fe7042e0cd0>] <--- THIS
2025-02-23 11:49:22.477710 p19410 dbg IPActorAddress.__init__(): on exit: baseaddr = 94.x.x.x <--- THIS
2025-02-23 11:49:22.480796 p19414 dbg IPActorAddress.__init__(): on entry: baseaddr = 94.x.x.x, external = True
2025-02-23 11:49:22.480904 p19414 dbg IPActorAddress.__init__(): on exit: baseaddr = 94.x.x.x
2025-02-23 11:49:22.481070 p19414 dbg ++++ Starting Admin from /var/lib/jenkins/.local/lib/python3.11/site-packages/thespian/__init__.py
2025-02-23 11:49:22.481194 p19414 I ++++ Admin started @ ActorAddr-(T|*94.x.x.x:1900) / gen (3, 10) / capabilities {'coordinator': False, 'ip': '192.168.14.3', 'Convention Address.IPv4': '192.168.14.2:1900', 'Thespian ActorSystem Name': 'multiprocTCPBase', 'Thespian ActorSystem Version': 2, 'Thespian Watch Supported': True, 'Python Version': (3, 11, 4, 'final', 0), 'Thespian Generation': (3, 10), 'Thespian Version': '1740307762476'}
2025-02-23 11:49:22.481662 p19414 dbg IPActorAddress.__init__(): on entry: baseaddr = 192.168.14.2, external = True
2025-02-23 11:49:22.481709 p19414 dbg IPActorAddress.__init__(): on exit: baseaddr = 192.168.14.2
2025-02-23 11:49:22.482125 p19414 dbg IPActorAddress.__init__(): on entry: baseaddr = 192.168.14.2, external = True
2025-02-23 11:49:22.482167 p19414 dbg IPActorAddress.__init__(): on exit: baseaddr = 192.168.14.2
2025-02-23 11:49:22.485938 p19414 dbg Admin of ReceiveEnvelope(from: ActorAddr-(T|*94.x.x.x:33791), <class 'thespian.system.messages.multiproc.LoggerConnected'> msg: <thespian.system.messages.multiproc.LoggerConnected object at 0x7fe7042fd2d0>)
2025-02-23 11:49:22.486279 p19414 dbg actualTransmit of TransportIntent(ActorAddr-(T|*192.168.14.3:37429)-pending-ExpiresIn_0:04:59.999851-<class 'thespian.system.messages.multiproc.EndpointConnected'>-<thespian.system.messages.multiproc.EndpointConnected object at 0x7fe7042fd090>-quit_0:04:59.999836)
2025-02-23 11:49:22.486445 p19414 dbg setup_convention(): enter
2025-02-23 11:49:22.486498 p19414 dbg IPActorAddress.__init__(): on entry: baseaddr = 192.168.14.2, external = True
2025-02-23 11:49:22.486547 p19414 dbg IPActorAddress.__init__(): on exit: baseaddr = 192.168.14.2
2025-02-23 11:49:22.486611 p19414 dbg setup_convention(): self.myAddress = ActorAddr-(T|*94.x.x.x:1900)
2025-02-23 11:49:22.486657 p19414 dbg setup_convention(): possibleLeader = ActorAddr-(T|192.168.14.2:1900)
2025-02-23 11:49:22.486701 p19414 I Admin registering with Convention @ ActorAddr-(T|192.168.14.2:1900) (first time)
I was hoping THESPIAN_BASE_IPADDR environment variable might allow us to workaround the problem, but its use surfaces another bug. This environment variable unconditionally changes the IP address in IPActorAddress constructor, but this class is used to store both local and non-local IP actor addresses, including the address of the convention leader. With convention leader address overwritten with THESPIAN_BASE_IPADDR, the convention registration is not attempted because local IP addresses are skipped in the process (there is no point sending convention registration to self). I haven't checked the details but I'm guessing THESPIAN_BASE_IPADDR was introduced when convention leader address was never stored in IPActorAddress class. Here is the same convention member startup sequence but with export THESPIAN_BASE_IPADDR=192.168.14.3. Note how the earlier problem is addressed but convention leader IP address is overwritten, and setup_convention() does not triggered convention registration.
2025-02-23 11:55:16.110977 p19650 dbg ThisSystem.__init__(): self._myAddresses = {'127.0.0.1', '', 'localhost', None, '192.168.14.3', '127.0.1.1', '94.130.140.253', '0.0.0.0'}
2025-02-23 11:55:16.112292 p19650 dbg TCPTransport.__init__(): externalAddr = ('192.168.14.2', 1900)
2025-02-23 11:55:16.112339 p19650 dbg IPActorAddress.__init__(): on entry: baseaddr = None, external = ('192.168.14.2', 1900)
2025-02-23 11:55:16.112380 p19650 dbg IPActorAddress.__init__(): on exit: baseaddr = 192.168.14.3
2025-02-23 11:55:16.112437 p19650 dbg IPActorAddress.__init__(): on entry: baseaddr = 192.168.14.2, external = True <--- THIS
2025-02-23 11:55:16.112473 p19650 dbg IPActorAddress.__init__(): on exit: baseaddr = 192.168.14.3 <--- THIS
2025-02-23 11:55:16.112519 p19650 dbg IPActorAddress.__init__(): on entry: baseaddr = None, external = [<thespian.actors.ActorAddress object at 0x7f784f9b8b90>]
2025-02-23 11:55:16.112562 p19650 dbg IPActorAddress.__init__(): on exit: baseaddr = 192.168.14.3
2025-02-23 11:55:16.112609 p19650 dbg TCPTransport.__init__(): self._adminAddr = ActorAddr-(T|*192.168.14.3:1900)
2025-02-23 11:55:16.112674 p19650 dbg IPActorAddress.__init__(): on entry: baseaddr = 192.168.14.3, external = True
2025-02-23 11:55:16.112710 p19650 dbg IPActorAddress.__init__(): on exit: baseaddr = 192.168.14.3
2025-02-23 11:55:16.112784 p19650 dbg IPActorAddress.__init__(): on entry: baseaddr = 192.168.14.2, external = True <--- THIS
2025-02-23 11:55:16.112819 p19650 dbg IPActorAddress.__init__(): on exit: baseaddr = 192.168.14.3 <--- THIS
2025-02-23 11:55:16.112864 p19650 dbg IPActorAddress.__init__(): on entry: baseaddr = None, external = [<thespian.actors.ActorAddress object at 0x7f784f9b8d50>]
2025-02-23 11:55:16.112900 p19650 dbg IPActorAddress.__init__(): on exit: baseaddr = 192.168.14.3
2025-02-23 11:55:16.116006 p19654 dbg IPActorAddress.__init__(): on entry: baseaddr = 192.168.14.3, external = True
2025-02-23 11:55:16.116118 p19654 dbg IPActorAddress.__init__(): on exit: baseaddr = 192.168.14.3
2025-02-23 11:55:16.116278 p19654 dbg ++++ Starting Admin from /var/lib/jenkins/.local/lib/python3.11/site-packages/thespian/__init__.py
2025-02-23 11:55:16.116397 p19654 I ++++ Admin started @ ActorAddr-(T|*192.168.14.3:1900) / gen (3, 10) / capabilities {'coordinator': False, 'ip': '192.168.14.3', 'Convention Address.IPv4': '192.168.14.2:1900', 'Thespian ActorSystem Name': 'multiprocTCPBase', 'Thespian ActorSystem Version': 2, 'Thespian Watch Supported': True, 'Python Version': (3, 11, 4, 'final', 0), 'Thespian Generation': (3, 10), 'Thespian Version': '1740308116112'}
2025-02-23 11:55:16.116868 p19654 dbg IPActorAddress.__init__(): on entry: baseaddr = 192.168.14.2, external = True <--- THIS
2025-02-23 11:55:16.116910 p19654 dbg IPActorAddress.__init__(): on exit: baseaddr = 192.168.14.3 <--- THIS
2025-02-23 11:55:16.117344 p19654 dbg IPActorAddress.__init__(): on entry: baseaddr = 192.168.14.2, external = True <--- THIS
2025-02-23 11:55:16.117388 p19654 dbg IPActorAddress.__init__(): on exit: baseaddr = 192.168.14.3 <--- THIS
2025-02-23 11:55:16.121171 p19654 dbg Admin of ReceiveEnvelope(from: ActorAddr-(T|*192.168.14.3:42097), <class 'thespian.system.messages.multiproc.LoggerConnected'> msg: <thespian.system.messages.multiproc.LoggerConnected object at 0x7f784f9d51d0>)
2025-02-23 11:55:16.121516 p19654 dbg actualTransmit of TransportIntent(ActorAddr-(T|*192.168.14.3:34583)-pending-ExpiresIn_0:04:59.999852-<class 'thespian.system.messages.multiproc.EndpointConnected'>-<thespian.system.messages.multiproc.EndpointConnected object at 0x7f784f9d4ad0>-quit_0:04:59.999833)
2025-02-23 11:55:16.121691 p19654 dbg setup_convention(): enter
2025-02-23 11:55:16.121742 p19654 dbg IPActorAddress.__init__(): on entry: baseaddr = 192.168.14.2, external = True <--- THIS
2025-02-23 11:55:16.121792 p19654 dbg IPActorAddress.__init__(): on exit: baseaddr = 192.168.14.3 <--- THIS
2025-02-23 11:55:16.121859 p19654 dbg setup_convention(): self.myAddress = ActorAddr-(T|*192.168.14.3:1900)
2025-02-23 11:55:16.121904 p19654 dbg setup_convention(): possibleLeader = ActorAddr-(T|*192.168.14.3:1900)
!!! <--- convention registration does not happen
Both problems seem easy to fix, I'll raise a PR.
After upgrading Thespian 3.10.1 to 4.0.0 in all our systems we've noticed local IP address detection does not work correctly on hosts with multiple interfaces and IP addresses where some communication paths are filtered, and some not.
After some digging I think the problem is due to 089a7f2 which was shipped in 3.10.6. This commit changes the returned type of
TCPTransport.getConventionAddress()fromTCPv4ActorAddresstolist[TCPv4ActorAddress]. The output ofgetConventionAddress()is passed asexternalargument toIPActorAddressconstructor in some code paths. The constructor code does not handlelisttype correctly.To demonstrate the problem let's assume the following setup with 2 hosts. The convention leader address is
192.168.14.2and is known to convention member at startup. The expected result is convention member will select192.168.14.3as its own IP address, because that's the IP address on which it can establish communication with convention leader address as per local routing (both hosts are in the same192.168.14.0/24subnet). The expected behavior is documented inmultiprocTCPBasesection in here. These host have another set of interfaces with public IP addresses which can communicate with the Internet, but Thespian traffic is blocked.With extra debug logs in
IPBase.pywe can see member incorrectly selects its own IP address as94.x.x.xdespiteexternalargument being non-empty. I've marked the important log lines with<--- THIS. Note how IP address selection works fine whenexternalis a tuple, not a list. The problem is additionally confirmed with printout ofself._adminAddrfromTCPTransportconstructor. I've modified__str__()ofIPActorAddressto not omit local IP address in such case but add*prefix instead, soActorAddr-(T|:1900)becomesActorAddr-(T|*94.x.x.x:1900). Also note how later inconvention_setup()local address is again94.x.x.x. The convention registration is attempted but later the process fails as communication is not possible. I've omitted that part.I was hoping
THESPIAN_BASE_IPADDRenvironment variable might allow us to workaround the problem, but its use surfaces another bug. This environment variable unconditionally changes the IP address inIPActorAddressconstructor, but this class is used to store both local and non-local IP actor addresses, including the address of the convention leader. With convention leader address overwritten withTHESPIAN_BASE_IPADDR, the convention registration is not attempted because local IP addresses are skipped in the process (there is no point sending convention registration to self). I haven't checked the details but I'm guessingTHESPIAN_BASE_IPADDRwas introduced when convention leader address was never stored inIPActorAddressclass. Here is the same convention member startup sequence but withexport THESPIAN_BASE_IPADDR=192.168.14.3. Note how the earlier problem is addressed but convention leader IP address is overwritten, andsetup_convention()does not triggered convention registration.Both problems seem easy to fix, I'll raise a PR.