Open neurobs opened 1 year ago
Is there an update on this thread? I am getting similar behaviour on a Windows environment.
Apologies: I missed this on the original posting.
The initial set of warnings looks to be similar to https://github.com/kquick/Thespian/issues/11.
The error indicates that there is some other process that is running and using port 1900 for communications. Port 1900 is the default port used by the multiprocTCPBase, although a different port can be specified for use (see the 'Admin Port' capability specification at https://thespianpy.com/doc/using.html#hH-9d33a877-b4f0-4012-9510-442d81b0837c). In a linux environment, a command like netstat -vanept | grep 1900
can be used to get more information on what process is using the port; there are similar commands available for both Windows and MacOS.
I've got a bit more information. To be clear for anyone else hopping on this thread, I'm getting a similar error to the original poster, but my environment is Windows 10 and Python 3.10.8. My code can be seen here. A few more notes on the behaviour I'm seeing
Traceback (most recent call last):
File "C:\Git\Scratch\ThespianBenchmarking\Main.py", line 23, in <module>
actor_sys = ActorSystem(ACTOR_SYS)
File "C:\Users\***************\.virtualenvs\ThespianBenchmarking-5ebENAd8\lib\site-packages\thespian\actors.py", line 637, in __init__
systemBase = self._startupActorSys(
File "C:\Users\***************\.virtualenvs\ThespianBenchmarking-5ebENAd8\lib\site-packages\thespian\actors.py", line 678, in _startupActorSys
systemBase = sbc(self, logDefs=logDefs)
File "C:\Users\***************\.virtualenvs\ThespianBenchmarking-5ebENAd8\lib\site-packages\thespian\system\multiprocTCPBase.py", line 28, in __init__
super(ActorSystemBase, self).__init__(system, logDefs)
File "C:\Users\***************\.virtualenvs\ThespianBenchmarking-5ebENAd8\lib\site-packages\thespian\system\multiprocCommon.py", line 83, in __init__
super(multiprocessCommon, self).__init__(system, logDefs)
File "C:\Users\***************\.virtualenvs\ThespianBenchmarking-5ebENAd8\lib\site-packages\thespian\system\systemBase.py", line 326, in __init__
self._startAdmin(self.adminAddr,
File "C:\Users\***************\.virtualenvs\ThespianBenchmarking-5ebENAd8\lib\site-packages\thespian\system\multiprocCommon.py", line 115, in _startAdmin
raise InvalidActorAddress(adminAddr,
thespian.actors.InvalidActorAddress: ActorAddr-(T|:1900) is not a valid ActorSystem admin
Process finished with exit code 1
Does anyone know of a reason why thespian would launch a process that listens on the port specified by the capabilities yet reports an InvalidActorAddress error?
I learned some more information. We can easily launch a multiprocTCPBase actor just fine from a wsl environment. The warnings and error are replicated when executed from Windows10 environment (possibly mac as well from the original post)
Also, I haven't had any issues with multiprocUDPBase from a Windows environment.
Moving forward, does anyone have feedback on these questions?
Good to hear that it works fine in one environment and we can focus on Windows. The MacOS error in the original port was probably a port conflict that we described previously, which is also indicated by the difference in the error messages, so below I'm focusing more on the Windows scenario you have.
The multiprocTCPBase
will open a TCP socket connection to the Admin (defaulting to port 1900), and then issue a message to that socket. It will then wait for a recognizable response to confirm that it is indeed communicating with the Admin (https://github.com/kquick/Thespian/blob/master/thespian/system/multiprocCommon.py#L113-L116). In this case, something is at the socket address, but the wrong response is being received. This may be due to some sort of Windows firewall.
One test would be to see if the following simple scripts can exchange a socket message under your Windows configuration:
client.py
:
import socket
s = socket.socket()
s.connect(('', 1900))
s.send(b'Hello')
print(s.recv(1024))
s.close()
print('Done')
server.py
import socket
s = socket.socket()
s.bind(('', 1900))
s.listen()
(r,a) = s.accept()
print('Got connection from:', a)
m = r.recv(1024)
print('Got message', m, 'from', a)
r.send(b'Goodbye')
r.close()
print('Done')
Run these two (one each in a pair of terminal sessions, starting the server first) and they should be able to communicate their messages. That will provide a basic verification of the socket communications that Thespian builds on top of.
Great test. Thank you for putting that together.
Using the client-server pair directly from the last message, when client tries to runs.connect(('',1900)
we see the following error OSError: [WinError 10049] The requested address is not valid in its context
from the original code. Revising that line of code to s.connect(('127.0.0.1',1900)
allowed the test to complete (client and server exchange messages and exit)
Also worth noting, port 1900 is also being used by svchost.exe which is listening on UDP. That didn't seem to prevent this test from running using port 1900 as long as client's connect command is revised as described
Ah yes, that was my mistake: an empty string corresponds to INADDR_ANY
which is valid for the server accept binding but not for the client transmit.
That confirms that the networking is reasonable. The next thing to check is the thespian internal log (see section 13.3 in the Using Thespian documentation: https://thespianpy.com/doc/using.html#hH-ce55494c-dd7a-4258-a1e8-b090c3bbb1e6). Since you are on Windows, this file will be placed in the Windows temporary location. You might need to increase the maximum size setting, but probably not since this is failing near the original startup. If you can provide that file (here or in a gist) we can see if there's something else Thespian is encountering.
I cleared the log and reran my test 3 times resulting in this file. Note that a different admin port was specified on the third attempt (8084)
2023-05-10 21:13:21.919145 p15524 dbg ++++ Starting Admin from C:\Users\*******************\.virtualenvs\ThespianBenchmarking-5ebENAd8\lib\site-packages\thespian\__init__.py
2023-05-10 21:13:21.920137 p15524 I ++++ Admin started @ ActorAddr-(T|:1900) / gen (3, 10)
2023-05-10 21:14:05.740313 p7040 dbg ++++ Starting Admin from C:\Users\*******************\.virtualenvs\ThespianBenchmarking-5ebENAd8\lib\site-packages\thespian\__init__.py
2023-05-10 21:14:05.740313 p7040 I ++++ Admin started @ ActorAddr-(T|:1900) / gen (3, 10)
2023-05-10 21:20:37.416800 p6752 dbg ++++ Starting Admin from C:\Users\*******************\.\.virtualenvs\ThespianBenchmarking-5ebENAd8\lib\site-packages\thespian\__init__.py
2023-05-10 21:20:37.417801 p6752 I ++++ Admin started @ ActorAddr-(T|:8084) / gen (3, 10)
Note that the log was only made when I invoked the application from a commandline. Nothing is added to the log file if it's invoked through an IDE like pycharm
That didn't provide much, although I forgot to ask you to set the THESPLOG_THRESHOLD
to DEBUG
. It didn't log any errors though, which is curious. What happens if you remove your initial shutdown line (https://github.com/ProlucidDavid/ThespianBenchmarking/blob/main/Main.py#L21)?
I ran the following tests (all with THESPLOG_THRESHOLD
to DEBUG
).
ActorSystem().shutdown()
still in the source codeActorSystem().shutdown()
is commented outActorSystem().shutdown()
still in the source codeActorSystem().shutdown()
is commented outThis is the resulting log file:
2023-05-11 09:39:46.497059 p20788 dbg ++++ Starting Admin from C:\Users\*******************\.virtualenvs\ThespianBenchmarking-5ebENAd8\lib\site-packages\thespian\__init__.py
2023-05-11 09:39:46.498028 p20788 I ++++ Admin started @ ActorAddr-(T|:1900) / gen (3, 10)
2023-05-11 09:40:16.838427 p5032 dbg ++++ Starting Admin from C:\Users\*******************\.virtualenvs\ThespianBenchmarking-5ebENAd8\lib\site-packages\thespian\__init__.py
2023-05-11 09:40:16.838427 p5032 I ++++ Admin started @ ActorAddr-(T|:1900) / gen (3, 10)
2023-05-11 09:41:45.606349 p11288 dbg actualTransmit of TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:04:59.999921-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x0000023C22C3BFA0>-quit_0:04:59.999904)
2023-05-11 09:41:45.607348 p11288 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51199) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:04:59.997940-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x0000023C22C3BFA0>-quit_0:04:59.997930)
2023-05-11 09:41:45.652352 p11288 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51199) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:00:34.956368-retry#1-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x0000023C22C3BFA0>-quit_0:04:59.953878)
2023-05-11 09:41:45.714570 p11288 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51199) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:01:09.939143-retry#2-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x0000023C22C3BFA0>-quit_0:04:59.891331)
2023-05-11 09:41:45.822906 p11288 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51199) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:01:44.893719-retry#3-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x0000023C22C3BFA0>-quit_0:04:59.783329)
2023-05-11 09:41:45.993730 p11288 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51199) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:02:19.830506-retry#4-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x0000023C22C3BFA0>-quit_0:04:59.612243)
2023-05-11 09:41:46.290737 p11288 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51199) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:02:54.703767-retry#5-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x0000023C22C3BFA0>-quit_0:04:59.314737)
2023-05-11 09:41:46.776300 p11288 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51199) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:03:29.515622-retry#6-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x0000023C22C3BFA0>-quit_0:04:58.829563)
2023-05-11 09:41:47.602991 p11288 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51199) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:04:04.173791-retry#7-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x0000023C22C3BFA0>-quit_0:04:58.002898)
2023-05-11 09:41:48.133201 p11288 dbg actualTransmit of TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:04:59.999644-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x0000023C22B8FB50>-quit_0:04:59.999561)
2023-05-11 09:41:48.137009 p11288 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51199) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:04:59.995700-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x0000023C22B8FB50>-quit_0:04:59.995654)
2023-05-11 09:41:48.181897 p11288 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51199) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:00:34.956647-retry#1-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x0000023C22B8FB50>-quit_0:04:59.950592)
2023-05-11 09:41:48.243303 p11288 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51199) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:01:09.939957-retry#2-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x0000023C22B8FB50>-quit_0:04:59.889275)
2023-05-11 09:41:48.348625 p11288 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51199) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:01:44.894602-retry#3-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x0000023C22B8FB50>-quit_0:04:59.782502)
2023-05-11 09:41:48.523436 p11288 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51199) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:02:19.827158-retry#4-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x0000023C22B8FB50>-quit_0:04:59.609186)
2023-05-11 09:41:48.818376 p11288 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51199) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:02:54.706825-retry#5-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x0000023C22B8FB50>-quit_0:04:59.314273)
2023-05-11 09:41:49.004574 p11288 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51199) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:04:38.599304-retry#8-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x0000023C22C3BFA0>-quit_0:04:56.601497)
2023-05-11 09:41:49.319337 p11288 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51199) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:03:29.500122-retry#6-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x0000023C22B8FB50>-quit_0:04:58.812651)
2023-05-11 09:41:50.640708 p11288 dbg actualTransmit of TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:04:59.999889-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x0000023C22C902B0>-quit_0:04:59.999868)
2023-05-11 09:41:50.641705 p11288 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51199) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:04:59.998799-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x0000023C22C902B0>-quit_0:04:59.998789)
2023-05-11 09:41:50.688593 p11288 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51199) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:00:34.954188-retry#1-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x0000023C22C902B0>-quit_0:04:59.952578)
2023-05-11 09:41:50.753595 p11288 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51199) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:01:09.935460-retry#2-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x0000023C22C902B0>-quit_0:04:59.887568)
2023-05-11 09:41:50.864062 p11288 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51199) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:01:44.891632-retry#3-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x0000023C22C902B0>-quit_0:04:59.777399)
2023-05-11 09:41:51.036416 p11288 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51199) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:02:19.829935-retry#4-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x0000023C22C902B0>-quit_0:04:59.605400)
2023-05-11 09:41:51.332403 p11288 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51199) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:02:54.704851-retry#5-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x0000023C22C902B0>-quit_0:04:59.308459)
2023-05-11 09:41:51.379596 p11288 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51199) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:04:54.226047-retry#9-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x0000023C22C3BFA0>-quit_0:04:54.226035)
2023-05-11 09:41:51.818945 p11288 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51199) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:03:29.514285-retry#6-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x0000023C22C902B0>-quit_0:04:58.822178)
2023-05-11 09:41:53.145714 p11288 dbg actualTransmit of TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:04:59.999893-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x0000023C22C902E0>-quit_0:04:59.999877)
2023-05-11 09:41:53.146549 p11288 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51199) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:04:03.672683-retry#7-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x0000023C22C902B0>-quit_0:04:57.494020)
2023-05-11 09:41:54.552086 p11288 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51199) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:04:38.595639-retry#8-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x0000023C22C902B0>-quit_0:04:56.089236)
2023-05-11 09:41:55.669754 p11288 dbg actualTransmit of TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:04:59.999724-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x0000023C22C90820>-quit_0:04:59.999666)
2023-05-11 09:41:55.674529 p11288 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51199) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:04:59.995482-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x0000023C22C90820>-quit_0:04:59.995440)
2023-05-11 09:41:55.719693 p11288 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51199) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:00:34.956663-retry#1-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x0000023C22C90820>-quit_0:04:59.950397)
2023-05-11 09:41:55.779908 p11288 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51199) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:01:09.941049-retry#2-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x0000023C22C90820>-quit_0:04:59.889816)
2023-05-11 09:41:55.888475 p11288 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51199) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:01:44.891891-retry#3-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x0000023C22C90820>-quit_0:04:59.780746)
2023-05-11 09:41:56.061149 p11288 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51199) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:02:19.827869-retry#4-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x0000023C22C90820>-quit_0:04:59.607928)
2023-05-11 09:41:56.359420 p11288 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51199) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:02:54.703817-retry#5-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x0000023C22C90820>-quit_0:04:59.310538)
2023-05-11 09:41:56.850822 p11288 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51199) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:03:29.508915-retry#6-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x0000023C22C90820>-quit_0:04:58.818145)
2023-05-11 09:41:56.928447 p11288 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51199) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:04:53.712235-retry#9-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x0000023C22C902B0>-quit_0:04:53.712209)
2023-05-11 09:41:58.189952 p11288 dbg actualTransmit of TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:04:59.999677-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x0000023C22C90E50>-quit_0:04:59.999612)
2023-05-11 09:41:58.193949 p11288 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51199) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:04:03.658250-retry#7-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x0000023C22C90820>-quit_0:04:57.475897)
2023-05-11 09:41:59.600666 p11288 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51199) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:04:38.594071-retry#8-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x0000023C22C90820>-quit_0:04:56.068383)
2023-05-11 09:42:59.517819 p3148 dbg actualTransmit of TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:04:59.999921-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x000002883FE16950>-quit_0:04:59.999907)
2023-05-11 09:42:59.518810 p3148 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51251) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:04:59.998208-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x000002883FE16950>-quit_0:04:59.998199)
2023-05-11 09:42:59.556819 p3148 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51251) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:00:34.963096-retry#1-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x000002883FE16950>-quit_0:04:59.960915)
2023-05-11 09:42:59.619034 p3148 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51251) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:01:09.939660-retry#2-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x000002883FE16950>-quit_0:04:59.898908)
2023-05-11 09:42:59.729468 p3148 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51251) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:01:44.891129-retry#3-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x000002883FE16950>-quit_0:04:59.788400)
2023-05-11 09:42:59.900066 p3148 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51251) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:02:19.830987-retry#4-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x000002883FE16950>-quit_0:04:59.617420)
2023-05-11 09:43:00.202254 p3148 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51251) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:02:54.698557-retry#5-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x000002883FE16950>-quit_0:04:59.315172)
2023-05-11 09:43:00.696588 p3148 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51251) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:03:29.506589-retry#6-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x000002883FE16950>-quit_0:04:58.819858)
2023-05-11 09:43:02.039022 p3148 dbg actualTransmit of TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:04:59.999836-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x000002883FC36560>-quit_0:04:59.999800)
2023-05-11 09:43:02.039976 p3148 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51251) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:04:03.657404-retry#7-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x000002883FE16950>-quit_0:04:57.476821)
2023-05-11 09:43:03.446655 p3148 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51251) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:04:38.595158-retry#8-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x000002883FE16950>-quit_0:04:56.071130)
2023-05-11 09:43:04.565706 p3148 dbg actualTransmit of TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:04:59.999761-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x000002883FE16E30>-quit_0:04:59.999742)
2023-05-11 09:43:04.566729 p3148 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51251) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:04:59.998650-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x000002883FE16E30>-quit_0:04:59.998641)
2023-05-11 09:43:04.612437 p3148 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51251) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:00:34.954186-retry#1-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x000002883FE16E30>-quit_0:04:59.952499)
2023-05-11 09:43:04.675696 p3148 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51251) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:01:09.937580-retry#2-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x000002883FE16E30>-quit_0:04:59.889425)
2023-05-11 09:43:04.787247 p3148 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51251) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:01:44.889617-retry#3-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x000002883FE16E30>-quit_0:04:59.778330)
2023-05-11 09:43:04.973874 p3148 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51251) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:02:19.815998-retry#4-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x000002883FE16E30>-quit_0:04:59.592498)
2023-05-11 09:43:05.268751 p3148 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51251) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:02:54.705782-retry#5-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x000002883FE16E30>-quit_0:04:59.296412)
2023-05-11 09:43:05.766184 p3148 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51251) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:03:29.503168-retry#6-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x000002883FE16E30>-quit_0:04:58.799127)
2023-05-11 09:43:05.831384 p3148 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51251) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:04:53.686269-retry#9-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x000002883FE16950>-quit_0:04:53.686227)
2023-05-11 09:43:07.076777 p3148 dbg actualTransmit of TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:04:59.999886-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x000002883FE16E00>-quit_0:04:59.999863)
2023-05-11 09:43:07.078824 p3148 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51251) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:04:59.998251-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x000002883FE16E00>-quit_0:04:59.998237)
2023-05-11 09:43:07.124857 p3148 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51251) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:00:34.954567-retry#1-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x000002883FE16E00>-quit_0:04:59.952275)
2023-05-11 09:43:07.189487 p3148 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51251) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:01:09.935892-retry#2-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x000002883FE16E00>-quit_0:04:59.887719)
2023-05-11 09:43:07.301029 p3148 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51251) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:01:44.889959-retry#3-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x000002883FE16E00>-quit_0:04:59.776304)
2023-05-11 09:43:07.471612 p3148 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51251) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:02:19.830661-retry#4-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x000002883FE16E00>-quit_0:04:59.606002)
2023-05-11 09:43:07.767710 p3148 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51251) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:02:54.705257-retry#5-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x000002883FE16E00>-quit_0:04:59.309855)
2023-05-11 09:43:08.266216 p3148 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51251) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:03:29.502663-retry#6-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x000002883FE16E00>-quit_0:04:58.810951)
2023-05-11 09:43:09.593640 p3148 dbg actualTransmit of TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:04:59.999892-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x000002883FE174F0>-quit_0:04:59.999869)
2023-05-11 09:43:09.594985 p3148 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51251) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:04:59.998286-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x000002883FE174F0>-quit_0:04:59.998243)
2023-05-11 09:43:09.641241 p3148 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51251) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:00:34.953842-retry#1-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x000002883FE174F0>-quit_0:04:59.951559)
2023-05-11 09:43:09.705010 p3148 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51251) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:01:09.937563-retry#2-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x000002883FE174F0>-quit_0:04:59.888215)
2023-05-11 09:43:09.811230 p3148 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51251) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:01:44.895060-retry#3-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x000002883FE174F0>-quit_0:04:59.781817)
2023-05-11 09:43:09.874155 p3148 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51251) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:04:49.642778-retry#10-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x000002883FE16950>-quit_0:04:49.642753)
2023-05-11 09:43:09.984549 p3148 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51251) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:02:19.827558-retry#4-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x000002883FE174F0>-quit_0:04:59.608874)
2023-05-11 09:43:10.284066 p3148 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51251) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:02:54.702424-retry#5-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x000002883FE174F0>-quit_0:04:59.309856)
2023-05-11 09:43:10.782392 p3148 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51251) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:03:29.502371-retry#6-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x000002883FE174F0>-quit_0:04:58.810518)
2023-05-11 09:43:12.122828 p3148 dbg actualTransmit of TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:04:59.999665-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x000002883FE176D0>-quit_0:04:59.999615)
2023-05-11 09:43:12.125827 p3148 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51251) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:04:03.658181-retry#7-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x000002883FE174F0>-quit_0:04:57.467603)
2023-05-11 09:43:13.527857 p3148 I Remote ActorAddr-(T|:1900) closed connection before ack received at ActorAddr-(T|:51251) for TransportIntent(ActorAddr-(T|:1900)-pending-ExpiresIn_0:04:38.599567-retry#8-<class 'thespian.system.messages.admin.QueryExists'>-<thespian.system.messages.admin.QueryExists object at 0x000002883FE174F0>-quit_0:04:56.066023)
I ralso epeated the tests and got a similar log file with an alternative admin port specified
Regarding the MacOS case,
lsof -i :1900
shows no processes using 1900, but I still get the exception. After this, lsof shows this:
COMMAND PID USER FD TYPE DEVICE SIZE/OFF NODE NAME
Python 69973 user 8u IPv4 0x75e2f1c7a8675787 0t0 TCP *:ssdp (LISTEN)
Python 69974 user 8u IPv4 0x75e2f1c7a8675787 0t0 TCP *:ssdp (LISTEN)
I did some investigation and fixed an issue that might be causing the behaviors observed above. Can you both try pulling the latest Thespian from master and re-run your tests. Also, after you pull, please delete thespian/importlib.pyc
if it exists before running your tests.
If this does not fix your problems, also note that I've created a thespian/diagnose.py
which is a standalone program to diagnose various startup issues. If you run it, it will show various diagnostic information on the screen and also write to a logfile. If your problems still exist, please post that logfile back here (it also includes the thesplog automatically, so you do not need to set any of the THESPLOG_x
environment variables or post that log independently). For comparison, I've provided a version of that logfile for my system here: https://gist.github.com/kquick/f5bec51dedf3723e34b993fe7e8e10e6
If the above fixes your problems, I will cut a new release; if not, I'm hoping we can iterate over updates to the diagnose.py to further identify what is going on in your environments.
Thank you for spending time looking into this. Unfortunately I am still getting the same behaviour with the multiprocTCP Actor System and the latest version of master.
I tried running diagnose.py
, but it crashes with this error:
Traceback (most recent call last):
File "C:\Git\Scratch\Thespian(kquick source)\thespian\diagnose.py", line 420, in <module>
d = Diagnoser(len(sys.argv) < 2 and sys.stdout.isatty())
File "C:\Git\Scratch\Thespian(kquick source)\thespian\diagnose.py", line 29, in __init__
kernel32.SetconsoleMode(kernel32.GetStdHandle(-11), 7)
File "C:\Python310\lib\ctypes\__init__.py", line 387, in __getattr__
func = self.__getitem__(name)
File "C:\Python310\lib\ctypes\__init__.py", line 392, in __getitem__
func = self._FuncPtr((name_or_ordinal, self))
AttributeError: function 'SetconsoleMode' not found
The thespian_diagnostics.log
file is made, but is empty because of that error
I don't have a Windows system to test on unfortunately. That may have been a mis-spelling (the c
in console might need to be capitalized), or you can comment out lines 26-30 and try running again; if the output contains some garbage characters you can run with an argument of simple
but either way an thespian_diagnostics.log
file should be created.
Any updates from your end, @ProlucidDavid or @neurobs ?
I get the same error as before using master. The diagnose.py log is attached. thespian_diagnostics.log
Thank you, @neurobs . The logs indicated that a simple client/server socket test is failing in your environment, which may (or may not) be indicative of the root issue for Thespian operations here. I've pushed some additional information gathering to the diagnose.py to try to gather more information. I appreciate your assistance in diagnosing this problem and I hope to find something revealing soon that will help resolve the problems you are seeing.
I'm not seeing any changes to dianose.py on Github, unless I'm doing something silly.
There's not a lot, but it's here: https://github.com/kquick/Thespian/commit/dfc6d3e865c05f929328b85e98671a5c8fc3a54a
The previous test seemed to hang somewhere in the socket shutdown, so this just generates a bit more information so I can see where it's happening to start looking for what might be occurring.
I was looking at the wrong repo. thespian_diagnostics.log
Very odd: that's hanging on the socket.shutdown call. There may be something about those calls on more recent versions of MacOS that is problematic. One thing you could additionally try for me is to comment out that line (line 373 of diagnose.py: s.shutdown(socket.SHUT_RDWR)
and re-run the diagnose script.
Another thing that might be causing issues is the under-configuration of your system that is causing various socket.getaddrinfo()
calls to fail (as noted by the diagnose script). It does not seem to cause a problem for a very simple socket connection as tested by diagnose.py, but for the more complex socket arrangements setup by Thespian this may be an issue. You can try assigning a name (via system configuration) although you might need to do some additional configuration:
scutil --set HostName {name}
scutil --set LocalHostName {name}
Please be aware these will make changes on your system so you may decline modifications like this if you are not comfortable with the effects.
Again, thank you for working with me on this and I apologize for the prolonged efforts: I no longer have access to a Mac system directly to try these things for myself, but I can say that Thespian worked just fine on a Mac as of approximately 12-18 months ago when I did have a functioning Mac.
I commented line 373 and set the HostName and LocalHostName. thespian_diagnostics.log
On MacOS using thespian 3.10.7, the multiprocTCPBase actor system configuration does not work. The exception is as follows:
The Mac firewall is not enabled.