Drop cloudpickle dependency by guilledk · Pull Request #133 · goodboy/tractor

guilledk · 2020-07-25T19:43:17Z

In the new trio backend, we were using cloudpickle to serialize the async function the child will have to pass to trio to run, but this function never changed, it was Actor._async_main, this function handles the connection and handshake with the parent actor.

The real problem was passing the subactor object instance to the newly spawned child.

tractor._actor.Actor init function params:

name: str,
rpc_module_paths: List[str],
uid: str,
loglevel: str,
arbiter_addr: Tuple[str, int]

This parameters are passed through the child shell arguments and parsed using argparse.

The problem is the following, when running tests/_test.py from the shell this is the output:

[guille@hardPC tractor]$ python tests/_test.py 
Jul 25 16:42:27 (no actor context, 161699, tractor._main)) [WARNING] tractor __init__.py:70 No actor could be found @ 127.0.0.1:1616
Jul 25 16:42:27 (no actor context, 161699, tractor._main)) [DEBUG] tractor _actor.py:209 arbiter Loaded RPC modules: {}
Jul 25 16:42:27 (arbiter, 161699, tractor._main)) [INFO] tractor _actor.py:897 Starting local <tractor._actor.Arbiter object at 0x7ff5b0c9ca90> @ 127.0.0.1:1616
Jul 25 16:42:27 (arbiter, 161699, tractor._actor.Actor._serve_forever)) [DEBUG] tractor _actor.py:695 Started tcp server(s) on [<trio.socket.socket fd=8, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('127.0.0.1', 1616)>]
Jul 25 16:42:27 (arbiter, 161699, tractor._actor.Actor._async_main)) [DEBUG] tractor _actor.py:602 Registering <tractor._actor.Arbiter object at 0x7ff5b0c9ca90> for role `arbiter` @ ('127.0.0.1', 1616)
Jul 25 16:42:27 (arbiter, 161699, tractor._actor.Actor._async_main)) [DEBUG] tractor _actor.py:611 Waiting on root nursery to complete
Jul 25 16:42:27 (arbiter, 161699, tractor._main)) [DEBUG] tractor _actor.py:209 __main__ Loaded RPC modules: {'__main__': '/home/guille/Documents/tractor/tests/_test.py'}
Jul 25 16:42:27 (arbiter, 161699, tractor._spawn.new_proc)) [INFO] tractor _spawn.py:180 Spawn actor with cmd: ['/home/guille/.pyenv/versions/3.8.4/bin/python', '-m', 'tractor._child', 'some_linguist', '__main__', '6d548b98-2c48-46f3-b069-5940a7383159', 'None', '127.0.0.1:0', '127.0.0.1:1616', '127.0.0.1:1616']
Jul 25 16:42:27 (arbiter, 161699, tractor._spawn.new_proc)) [INFO] tractor _spawn.py:214 Started <trio.Process ['/home/guille/.pyenv/versions/3.8.4/bin/python', '-m', 'tractor._child', 'some_linguist', '__main__', '6d548b98-2c48-46f3-b069-5940a7383159', 'None', '127.0.0.1:0', '127.0.0.1:1616', '127.0.0.1:1616']: running with PID 161746>
Jul 25 16:42:27 (arbiter, 161699, tractor._spawn.new_proc)) [DEBUG] tractor _actor.py:250 Waiting for peer ('some_linguist', '6d548b98-2c48-46f3-b069-5940a7383159') to connect
/home/guille/.pyenv/versions/3.8.4/lib/python3.8/runpy.py:127: RuntimeWarning: 'tractor._child' found in sys.modules after import of package 'tractor', but prior to execution of 'tractor._child'; this may result in unpredictable behaviour
  warn(RuntimeWarning(msg))
Jul 25 16:42:27 (arbiter, 161699, trio._highlevel_serve_listeners._run_handler)) [INFO] tractor _actor.py:302 New connection to us <Channel fd=10, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('127.0.0.1', 1616), raddr=('127.0.0.1', 43966)>
Jul 25 16:42:27 (arbiter, 161699, trio._highlevel_serve_listeners._run_handler)) [TRACE] tractor.ipc _ipc.py:131 send `('arbiter', '9ab46a83-9c58-43b2-b5fb-489e2397ae4c')`
Jul 25 16:42:27 (arbiter, 161699, trio._highlevel_serve_listeners._run_handler)) [TRACE] tractor.ipc _ipc.py:39 received b'\x92\xadsome_linguist\xd9$6d548b98-2c48-46f3-b069-5940a7383159'
Jul 25 16:42:27 (arbiter, 161699, trio._highlevel_serve_listeners._run_handler)) [INFO] tractor _actor.py:809 Handshake with actor ('some_linguist', '6d548b98-2c48-46f3-b069-5940a7383159')@('127.0.0.1', 43966) complete
Jul 25 16:42:27 (arbiter, 161699, trio._highlevel_serve_listeners._run_handler)) [DEBUG] tractor _actor.py:317 Waking channel waiters _ParkingLotStatistics(tasks_waiting=1)
Jul 25 16:42:27 (arbiter, 161699, trio._highlevel_serve_listeners._run_handler)) [TRACE] tractor _actor.py:326 Registered <Channel fd=10, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('127.0.0.1', 1616), raddr=('127.0.0.1', 43966)> for ('some_linguist', '6d548b98-2c48-46f3-b069-5940a7383159')
Jul 25 16:42:27 (arbiter, 161699, trio._highlevel_serve_listeners._run_handler)) [DEBUG] tractor _actor.py:432 Entering msg loop for <Channel fd=10, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('127.0.0.1', 1616), raddr=('127.0.0.1', 43966)> from ('some_linguist', '6d548b98-2c48-46f3-b069-5940a7383159')
Jul 25 16:42:27 (arbiter, 161699, tractor._spawn.new_proc)) [DEBUG] tractor _actor.py:253 ('some_linguist', '6d548b98-2c48-46f3-b069-5940a7383159') successfully connected back to us
Jul 25 16:42:27 (arbiter, 161699, trio._highlevel_serve_listeners._run_handler)) [INFO] tractor _actor.py:302 New connection to us <Channel fd=11, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('127.0.0.1', 1616), raddr=('127.0.0.1', 43968)>
Jul 25 16:42:27 (arbiter, 161699, trio._highlevel_serve_listeners._run_handler)) [TRACE] tractor.ipc _ipc.py:131 send `('arbiter', '9ab46a83-9c58-43b2-b5fb-489e2397ae4c')`
Jul 25 16:42:27 (arbiter, 161699, tractor._main)) [DEBUG] tractor _actor.py:389 Getting result queue for ('some_linguist', '6d548b98-2c48-46f3-b069-5940a7383159') cid 097c0d6a-6ab3-40ca-b701-10a681cb57d5
Jul 25 16:42:27 (arbiter, 161699, tractor._main)) [DEBUG] tractor _actor.py:414 Sending cmd to ('some_linguist', '6d548b98-2c48-46f3-b069-5940a7383159'): __main__.cellar_door({})
Jul 25 16:42:27 (arbiter, 161699, tractor._main)) [TRACE] tractor.ipc _ipc.py:131 send `{'cmd': ('__main__', 'cellar_door', {}, ('arbiter', '9ab46a83-9c58-43b2-b5fb-489e2397ae4c'), '097c0d6a-6ab3-40ca-b701-10a681cb57d5')}`
Jul 25 16:42:27 (arbiter, 161699, trio._highlevel_serve_listeners._run_handler)) [TRACE] tractor.ipc _ipc.py:39 received b'\x92\xadsome_linguist\xd9$6d548b98-2c48-46f3-b069-5940a7383159'
Jul 25 16:42:27 (arbiter, 161699, trio._highlevel_serve_listeners._run_handler)) [INFO] tractor _actor.py:809 Handshake with actor ('some_linguist', '6d548b98-2c48-46f3-b069-5940a7383159')@('127.0.0.1', 43968) complete
Jul 25 16:42:27 (arbiter, 161699, trio._highlevel_serve_listeners._run_handler)) [WARNING] tractor _actor.py:323 already have channel(s) for ('some_linguist', '6d548b98-2c48-46f3-b069-5940a7383159'):[<Channel fd=10, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('127.0.0.1', 1616), raddr=('127.0.0.1', 43966)>]?
Jul 25 16:42:27 (arbiter, 161699, trio._highlevel_serve_listeners._run_handler)) [TRACE] tractor _actor.py:326 Registered <Channel fd=11, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('127.0.0.1', 1616), raddr=('127.0.0.1', 43968)> for ('some_linguist', '6d548b98-2c48-46f3-b069-5940a7383159')
Jul 25 16:42:27 (arbiter, 161699, trio._highlevel_serve_listeners._run_handler)) [DEBUG] tractor _actor.py:432 Entering msg loop for <Channel fd=11, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('127.0.0.1', 1616), raddr=('127.0.0.1', 43968)> from ('some_linguist', '6d548b98-2c48-46f3-b069-5940a7383159')
Jul 25 16:42:27 (arbiter, 161699, trio._highlevel_serve_listeners._run_handler)) [TRACE] tractor.ipc _ipc.py:39 received b'\x81\xa3cmd\x95\xa4self\xaeregister_actor\x82\xa3uid\x92\xadsome_linguist\xd9$6d548b98-2c48-46f3-b069-5940a7383159\xa8sockaddr\x92\xa9127.0.0.1\xcd\x83\x87\x92\xadsome_linguist\xd9$6d548b98-2c48-46f3-b069-5940a7383159\xd9$bf6ce898-74fe-420f-9a88-e244d512c251'
Jul 25 16:42:27 (arbiter, 161699, trio._highlevel_serve_listeners._run_handler)) [TRACE] tractor _actor.py:453 Received msg {'cmd': ('self', 'register_actor', {'uid': ('some_linguist', '6d548b98-2c48-46f3-b069-5940a7383159'), 'sockaddr': ('127.0.0.1', 33671)}, ('some_linguist', '6d548b98-2c48-46f3-b069-5940a7383159'), 'bf6ce898-74fe-420f-9a88-e244d512c251')} from ('some_linguist', '6d548b98-2c48-46f3-b069-5940a7383159')
Jul 25 16:42:27 (arbiter, 161699, trio._highlevel_serve_listeners._run_handler)) [DEBUG] tractor _actor.py:476 Processing request from ('some_linguist', '6d548b98-2c48-46f3-b069-5940a7383159')
self.register_actor({'uid': ('some_linguist', '6d548b98-2c48-46f3-b069-5940a7383159'), 'sockaddr': ('127.0.0.1', 33671)})
Jul 25 16:42:27 (arbiter, 161699, trio._highlevel_serve_listeners._run_handler)) [DEBUG] tractor _actor.py:502 Spawning task for <bound method Arbiter.register_actor of <tractor._actor.Arbiter object at 0x7ff5b0c9ca90>>
Jul 25 16:42:27 (arbiter, 161699, trio._highlevel_serve_listeners._run_handler)) [TRACE] tractor.ipc _ipc.py:39 received b'\x82\xa5error\x82\xa6tb_str\xda\x01mTraceback (most recent call last):\n  File "/home/guille/Documents/tractor/tractor/_actor.py", line 494, in _process_messages\n    func = self._get_rpc_func(ns, funcname)\n  File "/home/guille/Documents/tractor/tractor/_actor.py", line 290, in _get_rpc_func\n    return getattr(self._mods[ns], funcname)\nAttributeError: module \'__main__\' has no attribute \'cellar_door\'\n\xa8type_str\xaeAttributeError\xa3cid\xd9$097c0d6a-6ab3-40ca-b701-10a681cb57d5'
Jul 25 16:42:27 (arbiter, 161699, trio._highlevel_serve_listeners._run_handler)) [TRACE] tractor _actor.py:453 Received msg {'error': {'tb_str': 'Traceback (most recent call last):\n  File "/home/guille/Documents/tractor/tractor/_actor.py", line 494, in _process_messages\n    func = self._get_rpc_func(ns, funcname)\n  File "/home/guille/Documents/tractor/tractor/_actor.py", line 290, in _get_rpc_func\n    return getattr(self._mods[ns], funcname)\nAttributeError: module \'__main__\' has no attribute \'cellar_door\'\n', 'type_str': 'AttributeError'}, 'cid': '097c0d6a-6ab3-40ca-b701-10a681cb57d5'} from ('some_linguist', '6d548b98-2c48-46f3-b069-5940a7383159')
Jul 25 16:42:27 (arbiter, 161699, trio._highlevel_serve_listeners._run_handler)) [DEBUG] tractor _actor.py:376 Delivering {'error': {'tb_str': 'Traceback (most recent call last):\n  File "/home/guille/Documents/tractor/tractor/_actor.py", line 494, in _process_messages\n    func = self._get_rpc_func(ns, funcname)\n  File "/home/guille/Documents/tractor/tractor/_actor.py", line 290, in _get_rpc_func\n    return getattr(self._mods[ns], funcname)\nAttributeError: module \'__main__\' has no attribute \'cellar_door\'\n', 'type_str': 'AttributeError'}, 'cid': '097c0d6a-6ab3-40ca-b701-10a681cb57d5'} from ('some_linguist', '6d548b98-2c48-46f3-b069-5940a7383159') to caller 097c0d6a-6ab3-40ca-b701-10a681cb57d5
Jul 25 16:42:27 (arbiter, 161699, trio._highlevel_serve_listeners._run_handler)) [DEBUG] tractor _actor.py:458 Waiting on next msg for <Channel fd=10, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('127.0.0.1', 1616), raddr=('127.0.0.1', 43966)> from ('some_linguist', '6d548b98-2c48-46f3-b069-5940a7383159')
Jul 25 16:42:27 (arbiter, 161699, tractor._main)) [ERROR] tractor _trionics.py:249 Nursery for ('arbiter', '9ab46a83-9c58-43b2-b5fb-489e2397ae4c') errored with ('some_linguist', '6d548b98-2c48-46f3-b069-5940a7383159')
Traceback (most recent call last):
  File "/home/guille/Documents/tractor/tractor/_actor.py", line 494, in _process_messages
    func = self._get_rpc_func(ns, funcname)
  File "/home/guille/Documents/tractor/tractor/_actor.py", line 290, in _get_rpc_func
    return getattr(self._mods[ns], funcname)
AttributeError: module '__main__' has no attribute 'cellar_door'
, 
Traceback (most recent call last):
  File "/home/guille/.pyenv/versions/3.8.4/lib/python3.8/site-packages/tractor/_trionics.py", line 228, in open_nursery
    yield anursery
  File "tests/_test.py", line 16, in test_most_beautiful_word
    portal = await n.run_in_actor('some_linguist', cellar_door)
  File "/home/guille/.pyenv/versions/3.8.4/lib/python3.8/site-packages/tractor/_trionics.py", line 118, in run_in_actor
    await portal._submit_for_result(
  File "/home/guille/.pyenv/versions/3.8.4/lib/python3.8/site-packages/tractor/_portal.py", line 176, in _submit_for_result
    self._expect_result = await self._submit(ns, func, kwargs)
  File "/home/guille/.pyenv/versions/3.8.4/lib/python3.8/site-packages/tractor/_portal.py", line 167, in _submit
    raise unpack_error(first_msg, self.channel)
tractor._exceptions.RemoteActorError: ('some_linguist', '6d548b98-2c48-46f3-b069-5940a7383159')
Traceback (most recent call last):
  File "/home/guille/Documents/tractor/tractor/_actor.py", line 494, in _process_messages
    func = self._get_rpc_func(ns, funcname)
  File "/home/guille/Documents/tractor/tractor/_actor.py", line 290, in _get_rpc_func
    return getattr(self._mods[ns], funcname)
AttributeError: module '__main__' has no attribute 'cellar_door'

Jul 25 16:42:27 (arbiter, 161699, tractor._main)) [DEBUG] tractor _trionics.py:139 Cancelling nursery
Jul 25 16:42:27 (arbiter, 161699, register_actor)) [TRACE] tractor.ipc _ipc.py:131 send `{'functype': 'function', 'cid': 'bf6ce898-74fe-420f-9a88-e244d512c251'}`
Jul 25 16:42:27 (arbiter, 161699, tractor._portal.Portal.cancel_actor)) [WARNING] tractor _portal.py:273 Sending actor cancel request to ('some_linguist', '6d548b98-2c48-46f3-b069-5940a7383159') on <Channel fd=10, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('127.0.0.1', 1616), raddr=('127.0.0.1', 43966)>
Jul 25 16:42:27 (arbiter, 161699, tractor._portal.Portal.cancel_actor)) [DEBUG] tractor _actor.py:389 Getting result queue for ('some_linguist', '6d548b98-2c48-46f3-b069-5940a7383159') cid 73579e25-6bcf-46e4-869c-b80add1a22ae
Jul 25 16:42:27 (arbiter, 161699, tractor._portal.Portal.cancel_actor)) [DEBUG] tractor _actor.py:414 Sending cmd to ('some_linguist', '6d548b98-2c48-46f3-b069-5940a7383159'): self.cancel({})
Jul 25 16:42:27 (arbiter, 161699, tractor._portal.Portal.cancel_actor)) [TRACE] tractor.ipc _ipc.py:131 send `{'cmd': ('self', 'cancel', {}, ('arbiter', '9ab46a83-9c58-43b2-b5fb-489e2397ae4c'), '73579e25-6bcf-46e4-869c-b80add1a22ae')}`
Jul 25 16:42:27 (arbiter, 161699, tractor._spawn.cancel_on_completion)) [DEBUG] tractor _spawn.py:107 Waiting on final result from ('some_linguist', '6d548b98-2c48-46f3-b069-5940a7383159')
Jul 25 16:42:27 (arbiter, 161699, tractor._spawn.cancel_on_completion)) [WARNING] tractor _portal.py:226 Portal for ('some_linguist', '6d548b98-2c48-46f3-b069-5940a7383159') not expecting a final result?
result() should only be called if subactor was spawned with `ActorNursery.run_in_actor()`
Jul 25 16:42:27 (arbiter, 161699, tractor._spawn.cancel_on_completion)) [DEBUG] tractor _spawn.py:123 Returning final result: <class 'tractor._exceptions.NoResult'>
Jul 25 16:42:27 (arbiter, 161699, tractor._spawn.cancel_on_completion)) [INFO] tractor _spawn.py:150 Cancelling ('some_linguist', '6d548b98-2c48-46f3-b069-5940a7383159') gracefully after result {result}
Jul 25 16:42:27 (arbiter, 161699, tractor._spawn.cancel_on_completion)) [WARNING] tractor _portal.py:273 Sending actor cancel request to ('some_linguist', '6d548b98-2c48-46f3-b069-5940a7383159') on <Channel fd=10, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('127.0.0.1', 1616), raddr=('127.0.0.1', 43966)>
Jul 25 16:42:27 (arbiter, 161699, tractor._spawn.cancel_on_completion)) [DEBUG] tractor _actor.py:389 Getting result queue for ('some_linguist', '6d548b98-2c48-46f3-b069-5940a7383159') cid 632d00fe-e239-49b3-ad59-ede3e04b7d41
Jul 25 16:42:27 (arbiter, 161699, tractor._spawn.cancel_on_completion)) [DEBUG] tractor _actor.py:414 Sending cmd to ('some_linguist', '6d548b98-2c48-46f3-b069-5940a7383159'): self.cancel({})
Jul 25 16:42:27 (arbiter, 161699, tractor._spawn.cancel_on_completion)) [TRACE] tractor.ipc _ipc.py:131 send `{'cmd': ('self', 'cancel', {}, ('arbiter', '9ab46a83-9c58-43b2-b5fb-489e2397ae4c'), '632d00fe-e239-49b3-ad59-ede3e04b7d41')}`
Jul 25 16:42:27 (arbiter, 161699, register_actor)) [TRACE] tractor.ipc _ipc.py:131 send `{'return': None, 'cid': 'bf6ce898-74fe-420f-9a88-e244d512c251'}`
Jul 25 16:42:27 (arbiter, 161699, trio._highlevel_serve_listeners._run_handler)) [INFO] tractor _actor.py:516 RPC func is <bound method Arbiter.register_actor of <tractor._actor.Arbiter object at 0x7ff5b0c9ca90>>
Jul 25 16:42:27 (arbiter, 161699, trio._highlevel_serve_listeners._run_handler)) [DEBUG] tractor _actor.py:521 Waiting on next msg for <Channel fd=11, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('127.0.0.1', 1616), raddr=('127.0.0.1', 43968)> from ('some_linguist', '6d548b98-2c48-46f3-b069-5940a7383159')
Jul 25 16:42:27 (arbiter, 161699, trio._highlevel_serve_listeners._run_handler)) [TRACE] tractor.ipc _ipc.py:39 received b'\x82\xa8functype\xadasyncfunction\xa3cid\xd9$73579e25-6bcf-46e4-869c-b80add1a22ae'
Jul 25 16:42:27 (arbiter, 161699, trio._highlevel_serve_listeners._run_handler)) [TRACE] tractor _actor.py:453 Received msg {'functype': 'asyncfunction', 'cid': '73579e25-6bcf-46e4-869c-b80add1a22ae'} from ('some_linguist', '6d548b98-2c48-46f3-b069-5940a7383159')
Jul 25 16:42:27 (arbiter, 161699, trio._highlevel_serve_listeners._run_handler)) [DEBUG] tractor _actor.py:376 Delivering {'functype': 'asyncfunction', 'cid': '73579e25-6bcf-46e4-869c-b80add1a22ae'} from ('some_linguist', '6d548b98-2c48-46f3-b069-5940a7383159') to caller 73579e25-6bcf-46e4-869c-b80add1a22ae
Jul 25 16:42:27 (arbiter, 161699, register_actor)) [INFO] tractor _actor.py:152 All RPC tasks have completed
Task <bound method Actor.cancel of <tractor._actor.Actor object at 0x7f3a115f5850>> was likely cancelled before it was started
Jul 25 16:42:27 (arbiter, 161699, trio._highlevel_serve_listeners._run_handler)) [DEBUG] tractor _actor.py:458 Waiting on next msg for <Channel fd=10, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('127.0.0.1', 1616), raddr=('127.0.0.1', 43966)> from ('some_linguist', '6d548b98-2c48-46f3-b069-5940a7383159')
Jul 25 16:42:27 (arbiter, 161699, trio._highlevel_serve_listeners._run_handler)) [ERROR] tractor.ipc _ipc.py:41 Stream connection ('127.0.0.1', 43966) broke
Jul 25 16:42:27 (arbiter, 161699, trio._highlevel_serve_listeners._run_handler)) [DEBUG] tractor.ipc _ipc.py:145 Closing <Channel fd=10, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('127.0.0.1', 1616)>
Jul 25 16:42:27 (arbiter, 161699, trio._highlevel_serve_listeners._run_handler)) [TRACE] tractor.ipc _ipc.py:39 received b''
Jul 25 16:42:27 (arbiter, 161699, trio._highlevel_serve_listeners._run_handler)) [DEBUG] tractor.ipc _ipc.py:45 Stream connection ('127.0.0.1', 43968) was closed
Jul 25 16:42:27 (arbiter, 161699, trio._highlevel_serve_listeners._run_handler)) [DEBUG] tractor.ipc _ipc.py:145 Closing <Channel fd=11, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('127.0.0.1', 1616), raddr=('127.0.0.1', 43968)>
Jul 25 16:42:27 (arbiter, 161699, trio._highlevel_serve_listeners._run_handler)) [DEBUG] tractor _actor.py:525 <Channel [closed] fd=-1, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6> from ('some_linguist', '6d548b98-2c48-46f3-b069-5940a7383159') disconnected
Jul 25 16:42:27 (arbiter, 161699, trio._highlevel_serve_listeners._run_handler)) [DEBUG] tractor _actor.py:543 Exiting msg loop for <Channel [closed] fd=-1, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6> from ('some_linguist', '6d548b98-2c48-46f3-b069-5940a7383159') with last msg:
{'functype': 'asyncfunction', 'cid': '73579e25-6bcf-46e4-869c-b80add1a22ae'}
Jul 25 16:42:27 (arbiter, 161699, trio._highlevel_serve_listeners._run_handler)) [DEBUG] tractor _actor.py:336 Releasing channel <Channel [closed] fd=-1, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6> from ('some_linguist', '6d548b98-2c48-46f3-b069-5940a7383159')
Jul 25 16:42:27 (arbiter, 161699, trio._highlevel_serve_listeners._run_handler)) [DEBUG] tractor _actor.py:343 Peers is defaultdict(<class 'list'>, {('some_linguist', '6d548b98-2c48-46f3-b069-5940a7383159'): [<Channel [closed] fd=-1, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6>]})
Jul 25 16:42:27 (arbiter, 161699, trio._highlevel_serve_listeners._run_handler)) [DEBUG] tractor _actor.py:525 <Channel [closed] fd=-1, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6> from ('some_linguist', '6d548b98-2c48-46f3-b069-5940a7383159') disconnected
Jul 25 16:42:27 (arbiter, 161699, trio._highlevel_serve_listeners._run_handler)) [DEBUG] tractor _actor.py:543 Exiting msg loop for <Channel [closed] fd=-1, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6> from ('some_linguist', '6d548b98-2c48-46f3-b069-5940a7383159') with last msg:
{'cmd': ('self', 'register_actor', {'uid': ('some_linguist', '6d548b98-2c48-46f3-b069-5940a7383159'), 'sockaddr': ('127.0.0.1', 33671)}, ('some_linguist', '6d548b98-2c48-46f3-b069-5940a7383159'), 'bf6ce898-74fe-420f-9a88-e244d512c251')}
Jul 25 16:42:27 (arbiter, 161699, trio._highlevel_serve_listeners._run_handler)) [DEBUG] tractor _actor.py:336 Releasing channel <Channel [closed] fd=-1, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6> from ('some_linguist', '6d548b98-2c48-46f3-b069-5940a7383159')
Jul 25 16:42:27 (arbiter, 161699, trio._highlevel_serve_listeners._run_handler)) [DEBUG] tractor _actor.py:340 No more channels for ('some_linguist', '6d548b98-2c48-46f3-b069-5940a7383159')
Jul 25 16:42:27 (arbiter, 161699, trio._highlevel_serve_listeners._run_handler)) [DEBUG] tractor _actor.py:343 Peers is defaultdict(<class 'list'>, {})
Jul 25 16:42:27 (arbiter, 161699, trio._highlevel_serve_listeners._run_handler)) [DEBUG] tractor _actor.py:347 Signalling no more peer channels
Jul 25 16:42:27 (arbiter, 161699, tractor._spawn.new_proc)) [DEBUG] tractor _spawn.py:328 Joined <trio.Process ['/home/guille/.pyenv/versions/3.8.4/bin/python', '-m', 'tractor._child', 'some_linguist', '__main__', '6d548b98-2c48-46f3-b069-5940a7383159', 'None', '127.0.0.1:0', '127.0.0.1:1616', '127.0.0.1:1616']: exited with status 0>
Jul 25 16:42:27 (arbiter, 161699, tractor._spawn.new_proc)) [WARNING] tractor _spawn.py:334 Cancelling existing result waiter task for ('some_linguist', '6d548b98-2c48-46f3-b069-5940a7383159')
Jul 25 16:42:28 (arbiter, 161699, tractor._portal.Portal.cancel_actor)) [WARNING] tractor _portal.py:283 May have failed to cancel ('some_linguist', '6d548b98-2c48-46f3-b069-5940a7383159')
Jul 25 16:42:28 (arbiter, 161699, tractor._spawn.cancel_on_completion)) [WARNING] tractor _portal.py:283 May have failed to cancel ('some_linguist', '6d548b98-2c48-46f3-b069-5940a7383159')
Jul 25 16:42:28 (arbiter, 161699, tractor._main)) [WARNING] tractor _trionics.py:278 Nursery cancelling due to ('some_linguist', '6d548b98-2c48-46f3-b069-5940a7383159')
Traceback (most recent call last):
  File "/home/guille/Documents/tractor/tractor/_actor.py", line 494, in _process_messages
    func = self._get_rpc_func(ns, funcname)
  File "/home/guille/Documents/tractor/tractor/_actor.py", line 290, in _get_rpc_func
    return getattr(self._mods[ns], funcname)
AttributeError: module '__main__' has no attribute 'cellar_door'

Jul 25 16:42:28 (arbiter, 161699, tractor._actor.Actor._async_main)) [DEBUG] tractor _actor.py:661 All peer channels are complete
Jul 25 16:42:28 (arbiter, 161699, tractor._actor.Actor._async_main)) [DEBUG] tractor _actor.py:774 Shutting down channel server
Traceback (most recent call last):
  File "tests/_test.py", line 23, in <module>
    tractor.run(test_most_beautiful_word)
  File "/home/guille/.pyenv/versions/3.8.4/lib/python3.8/site-packages/tractor/__init__.py", line 114, in run
    return trio.run(_main, async_fn, args, kwargs, arbiter_addr, name)
  File "/home/guille/.pyenv/versions/3.8.4/lib/python3.8/site-packages/trio/_core/_run.py", line 1896, in run
    raise runner.main_task_outcome.error
  File "/home/guille/.pyenv/versions/3.8.4/lib/python3.8/site-packages/tractor/__init__.py", line 91, in _main
    return await _start_actor(
  File "/home/guille/.pyenv/versions/3.8.4/lib/python3.8/site-packages/tractor/_actor.py", line 908, in _start_actor
    result = await main()
  File "tests/_test.py", line 16, in test_most_beautiful_word
    portal = await n.run_in_actor('some_linguist', cellar_door)
  File "/home/guille/.pyenv/versions/3.8.4/lib/python3.8/site-packages/tractor/_trionics.py", line 118, in run_in_actor
    await portal._submit_for_result(
  File "/home/guille/.pyenv/versions/3.8.4/lib/python3.8/site-packages/tractor/_portal.py", line 176, in _submit_for_result
    self._expect_result = await self._submit(ns, func, kwargs)
  File "/home/guille/.pyenv/versions/3.8.4/lib/python3.8/site-packages/tractor/_portal.py", line 167, in _submit
    raise unpack_error(first_msg, self.channel)
tractor._exceptions.RemoteActorError: ('some_linguist', '6d548b98-2c48-46f3-b069-5940a7383159')
Traceback (most recent call last):
  File "/home/guille/Documents/tractor/tractor/_actor.py", line 494, in _process_messages
    func = self._get_rpc_func(ns, funcname)
  File "/home/guille/Documents/tractor/tractor/_actor.py", line 290, in _get_rpc_func
    return getattr(self._mods[ns], funcname)
AttributeError: module '__main__' has no attribute 'cellar_door'

Closes #131

guilledk · 2020-07-25T22:28:34Z

Leavin another run trace here because of the rebase:

[guille@hardPC tractor]$ python _test.py 
Jul 25 19:27:32 (no actor context, 172964, tractor._main)) [WARNING] tractor __init__.py:70 No actor could be found @ 127.0.0.1:1616
Jul 25 19:27:32 (no actor context, 172964, tractor._main)) [DEBUG] tractor _actor.py:206 arbiter Loaded RPC modules: {}
Jul 25 19:27:32 (arbiter, 172964, tractor._main)) [INFO] tractor _actor.py:892 Starting local <tractor._actor.Arbiter object at 0x7fb2cb921df0> @ 127.0.0.1:1616
Jul 25 19:27:32 (arbiter, 172964, tractor._actor.Actor._serve_forever)) [DEBUG] tractor _actor.py:692 Started tcp server(s) on [<trio.socket.socket fd=8, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('127.0.0.1', 1616)>]
Jul 25 19:27:32 (arbiter, 172964, tractor._actor.Actor._async_main)) [DEBUG] tractor _actor.py:599 Registering <tractor._actor.Arbiter object at 0x7fb2cb921df0> for role `arbiter` @ ('127.0.0.1', 1616)
Jul 25 19:27:32 (arbiter, 172964, tractor._actor.Actor._async_main)) [DEBUG] tractor _actor.py:608 Waiting on root nursery to complete
Jul 25 19:27:32 (arbiter, 172964, tractor._main)) [DEBUG] tractor _actor.py:206 __main__ Loaded RPC modules: {'__main__': '/home/guille/Documents/tractor/_test.py'}
Jul 25 19:27:32 (arbiter, 172964, tractor._spawn.new_proc)) [INFO] tractor _spawn.py:180 Spawn actor with cmd: ['/home/guille/.pyenv/versions/3.8.4/bin/python', '-m', 'tractor._child', 'some_linguist', '__main__', 'b9ffae4f-f3ef-4cfa-9b86-f9b39a2ed3dd', 'None', '127.0.0.1:0', '127.0.0.1:1616', '127.0.0.1:1616']
Jul 25 19:27:32 (arbiter, 172964, tractor._spawn.new_proc)) [INFO] tractor _spawn.py:214 Started <trio.Process ['/home/guille/.pyenv/versions/3.8.4/bin/python', '-m', 'tractor._child', 'some_linguist', '__main__', 'b9ffae4f-f3ef-4cfa-9b86-f9b39a2ed3dd', 'None', '127.0.0.1:0', '127.0.0.1:1616', '127.0.0.1:1616']: running with PID 173011>
Jul 25 19:27:32 (arbiter, 172964, tractor._spawn.new_proc)) [DEBUG] tractor _actor.py:247 Waiting for peer ('some_linguist', 'b9ffae4f-f3ef-4cfa-9b86-f9b39a2ed3dd') to connect
/home/guille/.pyenv/versions/3.8.4/lib/python3.8/runpy.py:127: RuntimeWarning: 'tractor._child' found in sys.modules after import of package 'tractor', but prior to execution of 'tractor._child'; this may result in unpredictable behaviour
  warn(RuntimeWarning(msg))
Jul 25 19:27:33 (arbiter, 172964, trio._highlevel_serve_listeners._run_handler)) [INFO] tractor _actor.py:299 New connection to us <Channel fd=10, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('127.0.0.1', 1616), raddr=('127.0.0.1', 44552)>
Jul 25 19:27:33 (arbiter, 172964, trio._highlevel_serve_listeners._run_handler)) [TRACE] tractor.ipc _ipc.py:131 send `('arbiter', '8f0c3e1a-b455-4785-8f35-755b9f8a3991')`
Jul 25 19:27:33 (arbiter, 172964, trio._highlevel_serve_listeners._run_handler)) [TRACE] tractor.ipc _ipc.py:39 received b'\x92\xadsome_linguist\xd9$b9ffae4f-f3ef-4cfa-9b86-f9b39a2ed3dd'
Jul 25 19:27:33 (arbiter, 172964, trio._highlevel_serve_listeners._run_handler)) [INFO] tractor _actor.py:806 Handshake with actor ('some_linguist', 'b9ffae4f-f3ef-4cfa-9b86-f9b39a2ed3dd')@('127.0.0.1', 44552) complete
Jul 25 19:27:33 (arbiter, 172964, trio._highlevel_serve_listeners._run_handler)) [DEBUG] tractor _actor.py:314 Waking channel waiters _ParkingLotStatistics(tasks_waiting=1)
Jul 25 19:27:33 (arbiter, 172964, trio._highlevel_serve_listeners._run_handler)) [TRACE] tractor _actor.py:323 Registered <Channel fd=10, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('127.0.0.1', 1616), raddr=('127.0.0.1', 44552)> for ('some_linguist', 'b9ffae4f-f3ef-4cfa-9b86-f9b39a2ed3dd')
Jul 25 19:27:33 (arbiter, 172964, trio._highlevel_serve_listeners._run_handler)) [DEBUG] tractor _actor.py:429 Entering msg loop for <Channel fd=10, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('127.0.0.1', 1616), raddr=('127.0.0.1', 44552)> from ('some_linguist', 'b9ffae4f-f3ef-4cfa-9b86-f9b39a2ed3dd')
Jul 25 19:27:33 (arbiter, 172964, tractor._spawn.new_proc)) [DEBUG] tractor _actor.py:250 ('some_linguist', 'b9ffae4f-f3ef-4cfa-9b86-f9b39a2ed3dd') successfully connected back to us
Jul 25 19:27:33 (arbiter, 172964, tractor._main)) [DEBUG] tractor _actor.py:386 Getting result queue for ('some_linguist', 'b9ffae4f-f3ef-4cfa-9b86-f9b39a2ed3dd') cid ffcc6ff0-9af9-4f2e-96e0-dd0e9bf2f55c
Jul 25 19:27:33 (arbiter, 172964, tractor._main)) [DEBUG] tractor _actor.py:411 Sending cmd to ('some_linguist', 'b9ffae4f-f3ef-4cfa-9b86-f9b39a2ed3dd'): __main__.cellar_door({})
Jul 25 19:27:33 (arbiter, 172964, tractor._main)) [TRACE] tractor.ipc _ipc.py:131 send `{'cmd': ('__main__', 'cellar_door', {}, ('arbiter', '8f0c3e1a-b455-4785-8f35-755b9f8a3991'), 'ffcc6ff0-9af9-4f2e-96e0-dd0e9bf2f55c')}`
Jul 25 19:27:33 (arbiter, 172964, trio._highlevel_serve_listeners._run_handler)) [INFO] tractor _actor.py:299 New connection to us <Channel fd=11, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('127.0.0.1', 1616), raddr=('127.0.0.1', 44554)>
Jul 25 19:27:33 (arbiter, 172964, trio._highlevel_serve_listeners._run_handler)) [TRACE] tractor.ipc _ipc.py:131 send `('arbiter', '8f0c3e1a-b455-4785-8f35-755b9f8a3991')`
Jul 25 19:27:33 (arbiter, 172964, trio._highlevel_serve_listeners._run_handler)) [TRACE] tractor.ipc _ipc.py:39 received b'\x92\xadsome_linguist\xd9$b9ffae4f-f3ef-4cfa-9b86-f9b39a2ed3dd'
Jul 25 19:27:33 (arbiter, 172964, trio._highlevel_serve_listeners._run_handler)) [INFO] tractor _actor.py:806 Handshake with actor ('some_linguist', 'b9ffae4f-f3ef-4cfa-9b86-f9b39a2ed3dd')@('127.0.0.1', 44554) complete
Jul 25 19:27:33 (arbiter, 172964, trio._highlevel_serve_listeners._run_handler)) [WARNING] tractor _actor.py:320 already have channel(s) for ('some_linguist', 'b9ffae4f-f3ef-4cfa-9b86-f9b39a2ed3dd'):[<Channel fd=10, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('127.0.0.1', 1616), raddr=('127.0.0.1', 44552)>]?
Jul 25 19:27:33 (arbiter, 172964, trio._highlevel_serve_listeners._run_handler)) [TRACE] tractor _actor.py:323 Registered <Channel fd=11, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('127.0.0.1', 1616), raddr=('127.0.0.1', 44554)> for ('some_linguist', 'b9ffae4f-f3ef-4cfa-9b86-f9b39a2ed3dd')
Jul 25 19:27:33 (arbiter, 172964, trio._highlevel_serve_listeners._run_handler)) [DEBUG] tractor _actor.py:429 Entering msg loop for <Channel fd=11, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('127.0.0.1', 1616), raddr=('127.0.0.1', 44554)> from ('some_linguist', 'b9ffae4f-f3ef-4cfa-9b86-f9b39a2ed3dd')
Jul 25 19:27:33 (arbiter, 172964, trio._highlevel_serve_listeners._run_handler)) [TRACE] tractor.ipc _ipc.py:39 received b'\x82\xa5error\x82\xa6tb_str\xda\x01mTraceback (most recent call last):\n  File "/home/guille/Documents/tractor/tractor/_actor.py", line 491, in _process_messages\n    func = self._get_rpc_func(ns, funcname)\n  File "/home/guille/Documents/tractor/tractor/_actor.py", line 287, in _get_rpc_func\n    return getattr(self._mods[ns], funcname)\nAttributeError: module \'__main__\' has no attribute \'cellar_door\'\n\xa8type_str\xaeAttributeError\xa3cid\xd9$ffcc6ff0-9af9-4f2e-96e0-dd0e9bf2f55c'
Jul 25 19:27:33 (arbiter, 172964, trio._highlevel_serve_listeners._run_handler)) [TRACE] tractor _actor.py:450 Received msg {'error': {'tb_str': 'Traceback (most recent call last):\n  File "/home/guille/Documents/tractor/tractor/_actor.py", line 491, in _process_messages\n    func = self._get_rpc_func(ns, funcname)\n  File "/home/guille/Documents/tractor/tractor/_actor.py", line 287, in _get_rpc_func\n    return getattr(self._mods[ns], funcname)\nAttributeError: module \'__main__\' has no attribute \'cellar_door\'\n', 'type_str': 'AttributeError'}, 'cid': 'ffcc6ff0-9af9-4f2e-96e0-dd0e9bf2f55c'} from ('some_linguist', 'b9ffae4f-f3ef-4cfa-9b86-f9b39a2ed3dd')
Jul 25 19:27:33 (arbiter, 172964, trio._highlevel_serve_listeners._run_handler)) [DEBUG] tractor _actor.py:373 Delivering {'error': {'tb_str': 'Traceback (most recent call last):\n  File "/home/guille/Documents/tractor/tractor/_actor.py", line 491, in _process_messages\n    func = self._get_rpc_func(ns, funcname)\n  File "/home/guille/Documents/tractor/tractor/_actor.py", line 287, in _get_rpc_func\n    return getattr(self._mods[ns], funcname)\nAttributeError: module \'__main__\' has no attribute \'cellar_door\'\n', 'type_str': 'AttributeError'}, 'cid': 'ffcc6ff0-9af9-4f2e-96e0-dd0e9bf2f55c'} from ('some_linguist', 'b9ffae4f-f3ef-4cfa-9b86-f9b39a2ed3dd') to caller ffcc6ff0-9af9-4f2e-96e0-dd0e9bf2f55c
Jul 25 19:27:33 (arbiter, 172964, trio._highlevel_serve_listeners._run_handler)) [TRACE] tractor.ipc _ipc.py:39 received b'\x81\xa3cmd\x95\xa4self\xaeregister_actor\x82\xa3uid\x92\xadsome_linguist\xd9$b9ffae4f-f3ef-4cfa-9b86-f9b39a2ed3dd\xa8sockaddr\x92\xa9127.0.0.1\xcd\xa6\xad\x92\xadsome_linguist\xd9$b9ffae4f-f3ef-4cfa-9b86-f9b39a2ed3dd\xd9$48217e84-735e-4f1c-8e4b-d6dc76cc6d6e'
Jul 25 19:27:33 (arbiter, 172964, trio._highlevel_serve_listeners._run_handler)) [TRACE] tractor _actor.py:450 Received msg {'cmd': ('self', 'register_actor', {'uid': ('some_linguist', 'b9ffae4f-f3ef-4cfa-9b86-f9b39a2ed3dd'), 'sockaddr': ('127.0.0.1', 42669)}, ('some_linguist', 'b9ffae4f-f3ef-4cfa-9b86-f9b39a2ed3dd'), '48217e84-735e-4f1c-8e4b-d6dc76cc6d6e')} from ('some_linguist', 'b9ffae4f-f3ef-4cfa-9b86-f9b39a2ed3dd')
Jul 25 19:27:33 (arbiter, 172964, trio._highlevel_serve_listeners._run_handler)) [DEBUG] tractor _actor.py:473 Processing request from ('some_linguist', 'b9ffae4f-f3ef-4cfa-9b86-f9b39a2ed3dd')
self.register_actor({'uid': ('some_linguist', 'b9ffae4f-f3ef-4cfa-9b86-f9b39a2ed3dd'), 'sockaddr': ('127.0.0.1', 42669)})
Jul 25 19:27:33 (arbiter, 172964, trio._highlevel_serve_listeners._run_handler)) [DEBUG] tractor _actor.py:499 Spawning task for <bound method Arbiter.register_actor of <tractor._actor.Arbiter object at 0x7fb2cb921df0>>
Jul 25 19:27:33 (arbiter, 172964, trio._highlevel_serve_listeners._run_handler)) [DEBUG] tractor _actor.py:455 Waiting on next msg for <Channel fd=10, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('127.0.0.1', 1616), raddr=('127.0.0.1', 44552)> from ('some_linguist', 'b9ffae4f-f3ef-4cfa-9b86-f9b39a2ed3dd')
Jul 25 19:27:33 (arbiter, 172964, tractor._main)) [ERROR] tractor _trionics.py:249 Nursery for ('arbiter', '8f0c3e1a-b455-4785-8f35-755b9f8a3991') errored with ('some_linguist', 'b9ffae4f-f3ef-4cfa-9b86-f9b39a2ed3dd')
Traceback (most recent call last):
  File "/home/guille/Documents/tractor/tractor/_actor.py", line 491, in _process_messages
    func = self._get_rpc_func(ns, funcname)
  File "/home/guille/Documents/tractor/tractor/_actor.py", line 287, in _get_rpc_func
    return getattr(self._mods[ns], funcname)
AttributeError: module '__main__' has no attribute 'cellar_door'
, 
Traceback (most recent call last):
  File "/home/guille/Documents/tractor/tractor/_trionics.py", line 228, in open_nursery
    yield anursery
  File "_test.py", line 16, in test_most_beautiful_word
    portal = await n.run_in_actor('some_linguist', cellar_door)
  File "/home/guille/Documents/tractor/tractor/_trionics.py", line 118, in run_in_actor
    await portal._submit_for_result(
  File "/home/guille/Documents/tractor/tractor/_portal.py", line 176, in _submit_for_result
    self._expect_result = await self._submit(ns, func, kwargs)
  File "/home/guille/Documents/tractor/tractor/_portal.py", line 167, in _submit
    raise unpack_error(first_msg, self.channel)
tractor._exceptions.RemoteActorError: ('some_linguist', 'b9ffae4f-f3ef-4cfa-9b86-f9b39a2ed3dd')
Traceback (most recent call last):
  File "/home/guille/Documents/tractor/tractor/_actor.py", line 491, in _process_messages
    func = self._get_rpc_func(ns, funcname)
  File "/home/guille/Documents/tractor/tractor/_actor.py", line 287, in _get_rpc_func
    return getattr(self._mods[ns], funcname)
AttributeError: module '__main__' has no attribute 'cellar_door'

Jul 25 19:27:33 (arbiter, 172964, tractor._main)) [DEBUG] tractor _trionics.py:139 Cancelling nursery
Jul 25 19:27:33 (arbiter, 172964, register_actor)) [TRACE] tractor.ipc _ipc.py:131 send `{'functype': 'function', 'cid': '48217e84-735e-4f1c-8e4b-d6dc76cc6d6e'}`
Jul 25 19:27:33 (arbiter, 172964, tractor._portal.Portal.cancel_actor)) [WARNING] tractor _portal.py:273 Sending actor cancel request to ('some_linguist', 'b9ffae4f-f3ef-4cfa-9b86-f9b39a2ed3dd') on <Channel fd=10, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('127.0.0.1', 1616), raddr=('127.0.0.1', 44552)>
Jul 25 19:27:33 (arbiter, 172964, tractor._portal.Portal.cancel_actor)) [DEBUG] tractor _actor.py:386 Getting result queue for ('some_linguist', 'b9ffae4f-f3ef-4cfa-9b86-f9b39a2ed3dd') cid c9d38939-3c53-43ec-bd34-0f721c3a0f48
Jul 25 19:27:33 (arbiter, 172964, tractor._portal.Portal.cancel_actor)) [DEBUG] tractor _actor.py:411 Sending cmd to ('some_linguist', 'b9ffae4f-f3ef-4cfa-9b86-f9b39a2ed3dd'): self.cancel({})
Jul 25 19:27:33 (arbiter, 172964, tractor._portal.Portal.cancel_actor)) [TRACE] tractor.ipc _ipc.py:131 send `{'cmd': ('self', 'cancel', {}, ('arbiter', '8f0c3e1a-b455-4785-8f35-755b9f8a3991'), 'c9d38939-3c53-43ec-bd34-0f721c3a0f48')}`
Jul 25 19:27:33 (arbiter, 172964, tractor._spawn.cancel_on_completion)) [DEBUG] tractor _spawn.py:107 Waiting on final result from ('some_linguist', 'b9ffae4f-f3ef-4cfa-9b86-f9b39a2ed3dd')
Jul 25 19:27:33 (arbiter, 172964, tractor._spawn.cancel_on_completion)) [WARNING] tractor _portal.py:226 Portal for ('some_linguist', 'b9ffae4f-f3ef-4cfa-9b86-f9b39a2ed3dd') not expecting a final result?
result() should only be called if subactor was spawned with `ActorNursery.run_in_actor()`
Jul 25 19:27:33 (arbiter, 172964, tractor._spawn.cancel_on_completion)) [DEBUG] tractor _spawn.py:123 Returning final result: <class 'tractor._exceptions.NoResult'>
Jul 25 19:27:33 (arbiter, 172964, tractor._spawn.cancel_on_completion)) [INFO] tractor _spawn.py:150 Cancelling ('some_linguist', 'b9ffae4f-f3ef-4cfa-9b86-f9b39a2ed3dd') gracefully after result {result}
Jul 25 19:27:33 (arbiter, 172964, tractor._spawn.cancel_on_completion)) [WARNING] tractor _portal.py:273 Sending actor cancel request to ('some_linguist', 'b9ffae4f-f3ef-4cfa-9b86-f9b39a2ed3dd') on <Channel fd=10, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('127.0.0.1', 1616), raddr=('127.0.0.1', 44552)>
Jul 25 19:27:33 (arbiter, 172964, tractor._spawn.cancel_on_completion)) [DEBUG] tractor _actor.py:386 Getting result queue for ('some_linguist', 'b9ffae4f-f3ef-4cfa-9b86-f9b39a2ed3dd') cid ed45612d-f1f5-4a80-9cef-143d6e3269e2
Jul 25 19:27:33 (arbiter, 172964, tractor._spawn.cancel_on_completion)) [DEBUG] tractor _actor.py:411 Sending cmd to ('some_linguist', 'b9ffae4f-f3ef-4cfa-9b86-f9b39a2ed3dd'): self.cancel({})
Jul 25 19:27:33 (arbiter, 172964, tractor._spawn.cancel_on_completion)) [TRACE] tractor.ipc _ipc.py:131 send `{'cmd': ('self', 'cancel', {}, ('arbiter', '8f0c3e1a-b455-4785-8f35-755b9f8a3991'), 'ed45612d-f1f5-4a80-9cef-143d6e3269e2')}`
Task <bound method Actor.cancel of <tractor._actor.Actor object at 0x7f2a596e1400>> was likely cancelled before it was started
Jul 25 19:27:33 (arbiter, 172964, register_actor)) [TRACE] tractor.ipc _ipc.py:131 send `{'return': None, 'cid': '48217e84-735e-4f1c-8e4b-d6dc76cc6d6e'}`
Jul 25 19:27:33 (arbiter, 172964, trio._highlevel_serve_listeners._run_handler)) [TRACE] tractor.ipc _ipc.py:39 received b'\x82\xa8functype\xadasyncfunction\xa3cid\xd9$c9d38939-3c53-43ec-bd34-0f721c3a0f48'
Jul 25 19:27:33 (arbiter, 172964, trio._highlevel_serve_listeners._run_handler)) [TRACE] tractor _actor.py:450 Received msg {'functype': 'asyncfunction', 'cid': 'c9d38939-3c53-43ec-bd34-0f721c3a0f48'} from ('some_linguist', 'b9ffae4f-f3ef-4cfa-9b86-f9b39a2ed3dd')
Jul 25 19:27:33 (arbiter, 172964, trio._highlevel_serve_listeners._run_handler)) [DEBUG] tractor _actor.py:373 Delivering {'functype': 'asyncfunction', 'cid': 'c9d38939-3c53-43ec-bd34-0f721c3a0f48'} from ('some_linguist', 'b9ffae4f-f3ef-4cfa-9b86-f9b39a2ed3dd') to caller c9d38939-3c53-43ec-bd34-0f721c3a0f48
Jul 25 19:27:33 (arbiter, 172964, trio._highlevel_serve_listeners._run_handler)) [INFO] tractor _actor.py:513 RPC func is <bound method Arbiter.register_actor of <tractor._actor.Arbiter object at 0x7fb2cb921df0>>
Jul 25 19:27:33 (arbiter, 172964, trio._highlevel_serve_listeners._run_handler)) [DEBUG] tractor _actor.py:518 Waiting on next msg for <Channel fd=11, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('127.0.0.1', 1616), raddr=('127.0.0.1', 44554)> from ('some_linguist', 'b9ffae4f-f3ef-4cfa-9b86-f9b39a2ed3dd')
Jul 25 19:27:33 (arbiter, 172964, trio._highlevel_serve_listeners._run_handler)) [DEBUG] tractor _actor.py:455 Waiting on next msg for <Channel fd=10, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('127.0.0.1', 1616), raddr=('127.0.0.1', 44552)> from ('some_linguist', 'b9ffae4f-f3ef-4cfa-9b86-f9b39a2ed3dd')
Jul 25 19:27:33 (arbiter, 172964, register_actor)) [INFO] tractor _actor.py:152 All RPC tasks have completed
Jul 25 19:27:33 (arbiter, 172964, trio._highlevel_serve_listeners._run_handler)) [ERROR] tractor.ipc _ipc.py:41 Stream connection ('127.0.0.1', 44552) broke
Jul 25 19:27:33 (arbiter, 172964, trio._highlevel_serve_listeners._run_handler)) [DEBUG] tractor.ipc _ipc.py:145 Closing <Channel fd=10, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('127.0.0.1', 1616)>
Jul 25 19:27:33 (arbiter, 172964, trio._highlevel_serve_listeners._run_handler)) [DEBUG] tractor _actor.py:522 <Channel [closed] fd=-1, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6> from ('some_linguist', 'b9ffae4f-f3ef-4cfa-9b86-f9b39a2ed3dd') disconnected
Jul 25 19:27:33 (arbiter, 172964, trio._highlevel_serve_listeners._run_handler)) [DEBUG] tractor _actor.py:540 Exiting msg loop for <Channel [closed] fd=-1, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6> from ('some_linguist', 'b9ffae4f-f3ef-4cfa-9b86-f9b39a2ed3dd') with last msg:
{'functype': 'asyncfunction', 'cid': 'c9d38939-3c53-43ec-bd34-0f721c3a0f48'}
Jul 25 19:27:33 (arbiter, 172964, trio._highlevel_serve_listeners._run_handler)) [DEBUG] tractor _actor.py:333 Releasing channel <Channel [closed] fd=-1, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6> from ('some_linguist', 'b9ffae4f-f3ef-4cfa-9b86-f9b39a2ed3dd')
Jul 25 19:27:33 (arbiter, 172964, trio._highlevel_serve_listeners._run_handler)) [DEBUG] tractor _actor.py:340 Peers is defaultdict(<class 'list'>, {('some_linguist', 'b9ffae4f-f3ef-4cfa-9b86-f9b39a2ed3dd'): [<Channel fd=11, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('127.0.0.1', 1616)>]})
Jul 25 19:27:33 (arbiter, 172964, trio._highlevel_serve_listeners._run_handler)) [ERROR] tractor.ipc _ipc.py:41 Stream connection ('127.0.0.1', 44554) broke
Jul 25 19:27:33 (arbiter, 172964, trio._highlevel_serve_listeners._run_handler)) [DEBUG] tractor.ipc _ipc.py:145 Closing <Channel fd=11, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('127.0.0.1', 1616)>
Jul 25 19:27:33 (arbiter, 172964, trio._highlevel_serve_listeners._run_handler)) [DEBUG] tractor _actor.py:522 <Channel [closed] fd=-1, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6> from ('some_linguist', 'b9ffae4f-f3ef-4cfa-9b86-f9b39a2ed3dd') disconnected
Jul 25 19:27:33 (arbiter, 172964, trio._highlevel_serve_listeners._run_handler)) [DEBUG] tractor _actor.py:540 Exiting msg loop for <Channel [closed] fd=-1, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6> from ('some_linguist', 'b9ffae4f-f3ef-4cfa-9b86-f9b39a2ed3dd') with last msg:
{'cmd': ('self', 'register_actor', {'uid': ('some_linguist', 'b9ffae4f-f3ef-4cfa-9b86-f9b39a2ed3dd'), 'sockaddr': ('127.0.0.1', 42669)}, ('some_linguist', 'b9ffae4f-f3ef-4cfa-9b86-f9b39a2ed3dd'), '48217e84-735e-4f1c-8e4b-d6dc76cc6d6e')}
Jul 25 19:27:33 (arbiter, 172964, trio._highlevel_serve_listeners._run_handler)) [DEBUG] tractor _actor.py:333 Releasing channel <Channel [closed] fd=-1, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6> from ('some_linguist', 'b9ffae4f-f3ef-4cfa-9b86-f9b39a2ed3dd')
Jul 25 19:27:33 (arbiter, 172964, trio._highlevel_serve_listeners._run_handler)) [DEBUG] tractor _actor.py:337 No more channels for ('some_linguist', 'b9ffae4f-f3ef-4cfa-9b86-f9b39a2ed3dd')
Jul 25 19:27:33 (arbiter, 172964, trio._highlevel_serve_listeners._run_handler)) [DEBUG] tractor _actor.py:340 Peers is defaultdict(<class 'list'>, {})
Jul 25 19:27:33 (arbiter, 172964, trio._highlevel_serve_listeners._run_handler)) [DEBUG] tractor _actor.py:344 Signalling no more peer channels
Jul 25 19:27:33 (arbiter, 172964, tractor._spawn.new_proc)) [DEBUG] tractor _spawn.py:328 Joined <trio.Process ['/home/guille/.pyenv/versions/3.8.4/bin/python', '-m', 'tractor._child', 'some_linguist', '__main__', 'b9ffae4f-f3ef-4cfa-9b86-f9b39a2ed3dd', 'None', '127.0.0.1:0', '127.0.0.1:1616', '127.0.0.1:1616']: exited with status 0>
Jul 25 19:27:33 (arbiter, 172964, tractor._spawn.new_proc)) [WARNING] tractor _spawn.py:334 Cancelling existing result waiter task for ('some_linguist', 'b9ffae4f-f3ef-4cfa-9b86-f9b39a2ed3dd')
Jul 25 19:27:33 (arbiter, 172964, tractor._spawn.cancel_on_completion)) [WARNING] tractor _portal.py:283 May have failed to cancel ('some_linguist', 'b9ffae4f-f3ef-4cfa-9b86-f9b39a2ed3dd')
Jul 25 19:27:33 (arbiter, 172964, tractor._portal.Portal.cancel_actor)) [WARNING] tractor _portal.py:283 May have failed to cancel ('some_linguist', 'b9ffae4f-f3ef-4cfa-9b86-f9b39a2ed3dd')
Jul 25 19:27:33 (arbiter, 172964, tractor._main)) [WARNING] tractor _trionics.py:278 Nursery cancelling due to ('some_linguist', 'b9ffae4f-f3ef-4cfa-9b86-f9b39a2ed3dd')
Traceback (most recent call last):
  File "/home/guille/Documents/tractor/tractor/_actor.py", line 491, in _process_messages
    func = self._get_rpc_func(ns, funcname)
  File "/home/guille/Documents/tractor/tractor/_actor.py", line 287, in _get_rpc_func
    return getattr(self._mods[ns], funcname)
AttributeError: module '__main__' has no attribute 'cellar_door'

Jul 25 19:27:33 (arbiter, 172964, tractor._actor.Actor._async_main)) [DEBUG] tractor _actor.py:658 All peer channels are complete
Jul 25 19:27:33 (arbiter, 172964, tractor._actor.Actor._async_main)) [DEBUG] tractor _actor.py:771 Shutting down channel server
Traceback (most recent call last):
  File "_test.py", line 23, in <module>
    tractor.run(test_most_beautiful_word)
  File "/home/guille/Documents/tractor/tractor/__init__.py", line 114, in run
    return trio.run(_main, async_fn, args, kwargs, arbiter_addr, name)
  File "/home/guille/.pyenv/versions/3.8.4/lib/python3.8/site-packages/trio/_core/_run.py", line 1896, in run
    raise runner.main_task_outcome.error
  File "/home/guille/Documents/tractor/tractor/__init__.py", line 91, in _main
    return await _start_actor(
  File "/home/guille/Documents/tractor/tractor/_actor.py", line 903, in _start_actor
    result = await main()
  File "_test.py", line 16, in test_most_beautiful_word
    portal = await n.run_in_actor('some_linguist', cellar_door)
  File "/home/guille/Documents/tractor/tractor/_trionics.py", line 118, in run_in_actor
    await portal._submit_for_result(
  File "/home/guille/Documents/tractor/tractor/_portal.py", line 176, in _submit_for_result
    self._expect_result = await self._submit(ns, func, kwargs)
  File "/home/guille/Documents/tractor/tractor/_portal.py", line 167, in _submit
    raise unpack_error(first_msg, self.channel)
tractor._exceptions.RemoteActorError: ('some_linguist', 'b9ffae4f-f3ef-4cfa-9b86-f9b39a2ed3dd')
Traceback (most recent call last):
  File "/home/guille/Documents/tractor/tractor/_actor.py", line 491, in _process_messages
    func = self._get_rpc_func(ns, funcname)
  File "/home/guille/Documents/tractor/tractor/_actor.py", line 287, in _get_rpc_func
    return getattr(self._mods[ns], funcname)
AttributeError: module '__main__' has no attribute 'cellar_door'

…y after handshake.

tractor/_actor.py

tractor/_child.py

goodboy · 2020-07-27T18:29:26Z

tractor/_child.py

+
+    parser = argparse.ArgumentParser()
+
+    parser.add_argument("name")


as discussed we should only need 3 args here:

uid, loglevel, parent_addr

The rest can be sent at parent data transfer in Actor._async_main().

Also I think named args would be good, so like:
uid=('name', '34lkj345-345lkj3450345'), loglevel='info', etc..

tractor/_child.py

goodboy

Good work!
Left some notes 😺

Last CI think looks to be fixing up mypy stuff as well.

tractor/_child.py

tractor/_actor.py

tractor/_spawn.py

tractor/_actor.py

…el, in early child actor init.

tractor/_actor.py

In order to have reliable subactor startup we need the following sequence to take place: - connect to the parent actor, handshake and receive runtime state - load exposed modules into memory - start the channel server up fully using the provided bind address - finally, start processing new messages from the parent Add a bunch more comments to clarify all this.

goodboy · 2020-07-29T14:29:21Z

tractor/_child.py

+from ._entry import _trio_main
+
+
+"""This is the "bootloader" for actors started using the native trio backend.


Oh, I was gonna say move this to the top of file if you don't mind.

goodboy · 2020-07-29T14:29:50Z

tractor/_child.py

-    trio.run(cloudpickle.load(sys.stdin.buffer))
+
+    parser = argparse.ArgumentParser()
+


You can probably also drop these blank lines between argparse calls.

goodboy · 2020-07-29T14:30:43Z

tractor/_child.py

+
+    args = parser.parse_args()
+
+    subactor = Actor(


It's funny, __init__() almost feels kinda pointless now except for the mp case.

Start up sequence trickery

goodboy · 2020-07-29T19:00:59Z

Man, the races in that CI smh..

guilledk requested a review from goodboy July 25, 2020 19:43

guilledk linked an issue Jul 25, 2020 that may be closed by this pull request

Can we lose cloudpickle for spawning? Wait for bootstrap? #131

Closed

goodboy force-pushed the flaky_tests branch 9 times, most recently from df5e702 to 5a27065 Compare July 27, 2020 02:53

This was referenced Jul 27, 2020

Wen? Multiprocessing-native debugger now! #129

Merged

Should we just discard multiprocessing? #134

Open

guilledk changed the base branch from flaky_tests to master July 27, 2020 17:54

Guillermo Rodriguez added 2 commits July 27, 2020 14:55

Now passing additional initialization parameters through channel earl…

2a407be

…y after handshake.

Onlt await params in trio mode

e5dbf14

goodboy reviewed Jul 27, 2020

View reviewed changes

tractor/_actor.py Outdated Show resolved Hide resolved

goodboy reviewed Jul 27, 2020

View reviewed changes

tractor/_child.py Outdated Show resolved Hide resolved

goodboy reviewed Jul 27, 2020

View reviewed changes

tractor/_child.py Outdated Show resolved Hide resolved

goodboy requested changes Jul 27, 2020

View reviewed changes

Added named arguments to child init, and now passing less of them.

ef053eb

guilledk requested a review from goodboy July 28, 2020 00:06

Actually dropping the cloudpickle dependency from setup.py

8b44ec7

guilledk closed this Jul 28, 2020

guilledk reopened this Jul 28, 2020