#3744 closed defect (fixed)

integration/test_tor.py::test_onion_service_storage fails on macOS and Python 2.7

Reported by: sajith Owned by:
Priority: normal Milestone: undecided
Component: dev-infrastructure Version: n/a
Keywords: Cc:
Launchpad Bug:

Description

See https://github.com/tahoe-lafs/tahoe-lafs/runs/2915192820, for example.

This looks like a combination of a new tor version on Homebrew 0.4.6.6, Python 2.7, and macOS. I could not reproduce the error locally on macOS using tor 0.4.5.8, until I upgraded it to 0.4.6.6.

Error log from CI:

2021-06-25T15:14:01.0673620Z ==================================== ERRORS ====================================
2021-06-25T15:14:01.0674530Z _________________ ERROR at setup of test_onion_service_storage _________________
2021-06-25T15:14:01.0676040Z 
2021-06-25T15:14:01.0677570Z reactor = <twisted.internet.selectreactor.SelectReactor object at 0x1090dd910>
2021-06-25T15:14:01.0700780Z temp_dir = '/var/folders/24/8k48jl6d249_n_qfxwsl6xvm0000gn/T/tahoeK4n4lf'
2021-06-25T15:14:01.0702470Z chutney = '/var/folders/24/8k48jl6d249_n_qfxwsl6xvm0000gn/T/tahoeK4n4lf/chutney'
2021-06-25T15:14:01.0704090Z request = <SubRequest 'tor_network' for <Function test_onion_service_storage>>
2021-06-25T15:14:01.0704980Z 
2021-06-25T15:14:01.0706110Z     @pytest.fixture(scope='session')
2021-06-25T15:14:01.0707550Z     @pytest.mark.skipif(sys.platform.startswith('win'),
2021-06-25T15:14:01.0710380Z                         reason='Tor tests are unstable on Windows')
2021-06-25T15:14:01.0712210Z     def tor_network(reactor, temp_dir, chutney, request):
2021-06-25T15:14:01.0713060Z     
2021-06-25T15:14:01.0714430Z         # this is the actual "chutney" script at the root of a chutney checkout
2021-06-25T15:14:01.0716090Z         chutney_dir = chutney
2021-06-25T15:14:01.0717540Z         chut = join(chutney_dir, 'chutney')
2021-06-25T15:14:01.0718340Z     
2021-06-25T15:14:01.0728220Z         # now, as per Chutney's README, we have to create the network
2021-06-25T15:14:01.0730120Z         # ./chutney configure networks/basic
2021-06-25T15:14:01.0735630Z         # ./chutney start networks/basic
2021-06-25T15:14:01.0736350Z     
2021-06-25T15:14:01.0737040Z         env = environ.copy()
2021-06-25T15:14:01.0737940Z         env.update({"PYTHONPATH": join(chutney_dir, "lib")})
2021-06-25T15:14:01.0738890Z         proto = _DumpOutputProtocol(None)
2021-06-25T15:14:01.0739770Z         reactor.spawnProcess(
2021-06-25T15:14:01.0740580Z             proto,
2021-06-25T15:14:01.0741320Z             sys.executable,
2021-06-25T15:14:01.0742010Z             (
2021-06-25T15:14:01.0743600Z                 sys.executable, '-m', 'chutney.TorNet', 'configure',
2021-06-25T15:14:01.0744980Z                 join(chutney_dir, 'networks', 'basic'),
2021-06-25T15:14:01.0745750Z             ),
2021-06-25T15:14:01.0746480Z             path=join(chutney_dir),
2021-06-25T15:14:01.0747330Z             env=env,
2021-06-25T15:14:01.0748040Z         )
2021-06-25T15:14:01.0748900Z >       pytest_twisted.blockon(proto.done)
2021-06-25T15:14:01.0749550Z 
2021-06-25T15:14:01.0750300Z integration/conftest.py:504: 
2021-06-25T15:14:01.0751040Z _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
2021-06-25T15:14:01.0752440Z .tox/integration/lib/python2.7/site-packages/pytest_twisted.py:76: in blockon
2021-06-25T15:14:01.0753610Z     return blockon_default(d)
2021-06-25T15:14:01.0754350Z _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
2021-06-25T15:14:01.0754930Z 
2021-06-25T15:14:01.0756610Z d = <Deferred at 0x10b3002d0 current result: <twisted.python.failure.Failure twisted.internet.error.ProcessTerminated: A process has ended with a probable error condition: process ended with exit code 1.>>
2021-06-25T15:14:01.0758360Z 
2021-06-25T15:14:01.0759190Z     def blockon_default(d):
2021-06-25T15:14:01.0760050Z         current = greenlet.getcurrent()
2021-06-25T15:14:01.0760840Z         assert (
2021-06-25T15:14:01.0761640Z             current is not _instances.gr_twisted
2021-06-25T15:14:01.0762790Z         ), "blockon cannot be called from the twisted greenlet"
2021-06-25T15:14:01.0763580Z         result = []
2021-06-25T15:14:01.0764230Z     
2021-06-25T15:14:01.0764880Z         def cb(r):
2021-06-25T15:14:01.0765650Z             result.append(r)
2021-06-25T15:14:01.0766620Z             if greenlet.getcurrent() is not current:
2021-06-25T15:14:01.0767550Z                 current.switch(result)
2021-06-25T15:14:01.0768250Z     
2021-06-25T15:14:01.0768980Z         d.addCallbacks(cb, cb)
2021-06-25T15:14:01.0769760Z         if not result:
2021-06-25T15:14:01.0770610Z             _result = _instances.gr_twisted.switch()
2021-06-25T15:14:01.0771600Z             assert _result is result, "illegal switch in blockon"
2021-06-25T15:14:01.0772390Z     
2021-06-25T15:14:01.0773150Z         if isinstance(result[0], failure.Failure):
2021-06-25T15:14:01.0774060Z >           result[0].raiseException()
2021-06-25T15:14:01.0775200Z E           ProcessTerminated: A process has ended with a probable error condition: process ended with exit code 1.
2021-06-25T15:14:01.0776100Z 
2021-06-25T15:14:01.0777660Z .tox/integration/lib/python2.7/site-packages/pytest_twisted.py:97: ProcessTerminated
2021-06-25T15:14:01.0779460Z ---------------------------- Captured stdout setup -----------------------------
2021-06-25T15:14:01.0781070Z Cloning into '/var/folders/24/8k48jl6d249_n_qfxwsl6xvm0000gn/T/tahoeK4n4lf/chutney'...
2021-06-25T15:14:01.0783580Z HEAD is now at 99bd06c Merge remote-tracking branch 'tor-github/pr/66'
2021-06-25T15:14:01.0786070Z NOTE: creating u'/private/var/folders/24/8k48jl6d249_n_qfxwsl6xvm0000gn/T/tahoeK4n4lf/chutney/net/nodes.1624634026', linking to u'/private/var/folders/24/8k48jl6d249_n_qfxwsl6xvm0000gn/T/tahoeK4n4lf/chutney/net/nodes'
2021-06-25T15:14:01.0788150Z Creating identity key for test000a     with tor-gencert
2021-06-25T15:14:01.0789680Z Creating identity key for test001a     with tor-gencert
2021-06-25T15:14:01.0791210Z Creating identity key for test002a     with tor-gencert
2021-06-25T15:14:01.0792710Z <type 'exceptions.AssertionError'>
2021-06-25T15:14:01.0794390Z Python 2.7.18: /Users/runner/work/tahoe-lafs/tahoe-lafs/.tox/integration/bin/python
2021-06-25T15:14:01.0795470Z Fri Jun 25 15:13:49 2021
2021-06-25T15:14:01.0796130Z 
2021-06-25T15:14:01.0797060Z A problem occurred in a Python script.  Here is the sequence of
2021-06-25T15:14:01.0798200Z function calls leading up to the error, in the order they occurred.
2021-06-25T15:14:01.0799230Z 
2021-06-25T15:14:01.0800930Z  /Users/runner/hostedtoolcache/Python/2.7.18/x64/lib/python2.7/runpy.py in _run_module_as_main(mod_name='chutney.TorNet', alter_argv=1)
2021-06-25T15:14:01.0802180Z   172         sys.argv[0] = fname
2021-06-25T15:14:01.0803140Z   173     return _run_code(code, main_globals, None,
2021-06-25T15:14:01.0804140Z   174                      "__main__", fname, loader, pkg_name)
2021-06-25T15:14:01.0804950Z   175 
2021-06-25T15:14:01.0805860Z   176 def run_module(mod_name, init_globals=None,
2021-06-25T15:14:01.0807540Z fname = '/private/var/folders/24/8k48jl6d249_n_qfxwsl6xvm0000gn/T/tahoeK4n4lf/chutney/lib/chutney/TorNet.py'
2021-06-25T15:14:01.0808850Z loader = <pkgutil.ImpLoader instance>
2021-06-25T15:14:01.0810220Z pkg_name = 'chutney'
2021-06-25T15:14:01.0810940Z 
2021-06-25T15:14:01.0817100Z  /Users/runner/hostedtoolcache/Python/2.7.18/x64/lib/python2.7/runpy.py in _run_code(code=<code object <module> at 0x10cdb9830, file "/pri...oeK4n4lf/chutney/lib/chutney/TorNet.py", line 11>, run_globals={'ConfigureNodes': <function ConfigureNodes>, 'DEFAULTS': {u'CUR_BOOTSTRAP_PHASE': 1, u'CUR_CONFIG_PHASE': 1, u'CUR_LAUNCH_PHASE': 1, u'auth_cert_lifetime': 12, u'authorities': u'AlternateDirAuthority bleargh bad torrc file!', u'authority': False, u'bootstrap_time': 60, u'bridge': False, u'bridgeauthority': False, u'bridges': u'Bridge bleargh bad torrc file!', ...}, 'KNOWN_REQUIREMENTS': {u'IPV6': <function memoized_fn>}, 'LocalNodeBuilder': <class '__main__.LocalNodeBuilder'>, 'LocalNodeController': <class '__main__.LocalNodeController'>, 'MissingBinaryException': <class '__main__.MissingBinaryException'>, 'Network': <class '__main__.Network'>, 'Node': <class '__main__.Node'>, 'NodeBuilder': <class '__main__.NodeBuilder'>, 'NodeController': <class '__main__.NodeController'>, ...}, init_globals=None, mod_name='__main__', mod_fname='/private/var/folders/24/8k48jl6d249_n_qfxwsl6xvm0000gn/T/tahoeK4n4lf/chutney/lib/chutney/TorNet.py', mod_loader=<pkgutil.ImpLoader instance>, pkg_name='chutney')
2021-06-25T15:14:01.0822690Z    70                        __loader__ = mod_loader,
2021-06-25T15:14:01.0823740Z    71                        __package__ = pkg_name)
2021-06-25T15:14:01.0824700Z    72     exec code in run_globals
2021-06-25T15:14:01.0825610Z    73     return run_globals
2021-06-25T15:14:01.0826380Z    74 
2021-06-25T15:14:01.0827450Z code = <code object <module> at 0x10cdb9830, file "/pri...oeK4n4lf/chutney/lib/chutney/TorNet.py", line 11>
2021-06-25T15:14:01.0833100Z run_globals = {'ConfigureNodes': <function ConfigureNodes>, 'DEFAULTS': {u'CUR_BOOTSTRAP_PHASE': 1, u'CUR_CONFIG_PHASE': 1, u'CUR_LAUNCH_PHASE': 1, u'auth_cert_lifetime': 12, u'authorities': u'AlternateDirAuthority bleargh bad torrc file!', u'authority': False, u'bootstrap_time': 60, u'bridge': False, u'bridgeauthority': False, u'bridges': u'Bridge bleargh bad torrc file!', ...}, 'KNOWN_REQUIREMENTS': {u'IPV6': <function memoized_fn>}, 'LocalNodeBuilder': <class '__main__.LocalNodeBuilder'>, 'LocalNodeController': <class '__main__.LocalNodeController'>, 'MissingBinaryException': <class '__main__.MissingBinaryException'>, 'Network': <class '__main__.Network'>, 'Node': <class '__main__.Node'>, 'NodeBuilder': <class '__main__.NodeBuilder'>, 'NodeController': <class '__main__.NodeController'>, ...}
2021-06-25T15:14:01.0836480Z 
2021-06-25T15:14:01.0837590Z  /private/var/folders/24/8k48jl6d249_n_qfxwsl6xvm0000gn/T/tahoeK4n4lf/chutney/lib/chutney/TorNet.py in <module>()
2021-06-25T15:14:01.0839170Z  2733         return -1
2021-06-25T15:14:01.0840930Z  2734     return 0
2021-06-25T15:14:01.0841660Z  2735 
2021-06-25T15:14:01.0844740Z  2736 if __name__ == '__main__':
2021-06-25T15:14:01.0845670Z  2737     sys.exit(main())
2021-06-25T15:14:01.0846940Z sys = <module 'sys' (built-in)>
2021-06-25T15:14:01.0848160Z sys.exit = <built-in function exit>
2021-06-25T15:14:01.0849180Z main = <function main>
2021-06-25T15:14:01.0849740Z 
2021-06-25T15:14:01.0850790Z  /private/var/folders/24/8k48jl6d249_n_qfxwsl6xvm0000gn/T/tahoeK4n4lf/chutney/lib/chutney/TorNet.py in main()
2021-06-25T15:14:01.0852100Z  2729     args = parseArgs()
2021-06-25T15:14:01.0853410Z  2730     f = open(args['network_cfg'])
2021-06-25T15:14:01.0854730Z  2731     result = runConfigFile(args['action'], f.read())
2021-06-25T15:14:01.0855570Z  2732     if result is False:
2021-06-25T15:14:01.0856640Z  2733         return -1
2021-06-25T15:14:01.0857400Z result undefined
2021-06-25T15:14:01.0858220Z global runConfigFile = <function runConfigFile>
2021-06-25T15:14:01.0860070Z args = {u'action': 'configure', u'network_cfg': '/var/folders/24/8k48jl6d249_n_qfxwsl6xvm0000gn/T/tahoeK4n4lf/chutney/networks/basic'}
2021-06-25T15:14:01.0861860Z f = <open file '/var/folders/24/8k48jl6d249_n_qfxwsl.../T/tahoeK4n4lf/chutney/networks/basic', mode 'r'>
2021-06-25T15:14:01.0863320Z f.read = <built-in method read of file object>
2021-06-25T15:14:01.0863990Z 
2021-06-25T15:14:01.0865950Z  /private/var/folders/24/8k48jl6d249_n_qfxwsl6xvm0000gn/T/tahoeK4n4lf/chutney/lib/chutney/TorNet.py in runConfigFile(verb='configure', data='# By default, Authorities are not configured as ....getN(5) + Client.getN(2)\n\nConfigureNodes(NODES)\n')
2021-06-25T15:14:01.0868570Z  2709         return
2021-06-25T15:14:01.0869690Z  2710 
2021-06-25T15:14:01.0870510Z  2711     return getattr(network, verb)()
2021-06-25T15:14:01.0871210Z  2712 
2021-06-25T15:14:01.0871850Z  2713 
2021-06-25T15:14:01.0873140Z builtingetattr = <built-in function getattr>
2021-06-25T15:14:01.0874060Z network = <__main__.Network object>
2021-06-25T15:14:01.0875220Z verb = 'configure'
2021-06-25T15:14:01.0875830Z 
2021-06-25T15:14:01.0876970Z  /private/var/folders/24/8k48jl6d249_n_qfxwsl6xvm0000gn/T/tahoeK4n4lf/chutney/lib/chutney/TorNet.py in configure(self=<__main__.Network object>)
2021-06-25T15:14:01.0878030Z  2323 
2021-06-25T15:14:01.0878740Z  2324         for b in builders:
2021-06-25T15:14:01.0879500Z  2325             b.config(network)
2021-06-25T15:14:01.0880160Z  2326 
2021-06-25T15:14:01.0880880Z  2327         for b in builders:
2021-06-25T15:14:01.0881710Z b = <__main__.LocalNodeBuilder object>
2021-06-25T15:14:01.0882820Z b.config = <bound method LocalNodeBuilder.config of <__main__.LocalNodeBuilder object>>
2021-06-25T15:14:01.0883930Z network = <__main__.Network object>
2021-06-25T15:14:01.0884530Z 
2021-06-25T15:14:01.0885760Z  /private/var/folders/24/8k48jl6d249_n_qfxwsl6xvm0000gn/T/tahoeK4n4lf/chutney/lib/chutney/TorNet.py in config(self=<__main__.LocalNodeBuilder object>, net=<__main__.Network object>)
2021-06-25T15:14:01.0887030Z   691     def config(self, net):
2021-06-25T15:14:01.0888220Z   692         """Called to configure a node: creates a torrc file for it."""
2021-06-25T15:14:01.0888920Z   693         self._createTorrcFile()
2021-06-25T15:14:01.0889480Z   694         # self._createScripts()
2021-06-25T15:14:01.0889950Z   695 
2021-06-25T15:14:01.0890450Z self = <__main__.LocalNodeBuilder object>
2021-06-25T15:14:01.0892020Z self._createTorrcFile = <bound method LocalNodeBuilder._createTorrcFile of <__main__.LocalNodeBuilder object>>
2021-06-25T15:14:01.0893480Z 
2021-06-25T15:14:01.0895380Z  /private/var/folders/24/8k48jl6d249_n_qfxwsl6xvm0000gn/T/tahoeK4n4lf/chutney/lib/chutney/TorNet.py in _createTorrcFile(self=<__main__.LocalNodeBuilder object>, checkOnly=False)
2021-06-25T15:14:01.0897370Z   628         # the options that the current tor binary doesn't support
2021-06-25T15:14:01.0898660Z   629         tor = self._env['tor']
2021-06-25T15:14:01.0899280Z   630         tor_version = get_tor_version(tor)
2021-06-25T15:14:01.0899850Z   631         torrc_opts = get_torrc_options(tor)
2021-06-25T15:14:01.0900480Z   632         # check if each option is supported before writing it
2021-06-25T15:14:01.0901030Z tor_version undefined
2021-06-25T15:14:01.0901580Z global get_tor_version = <function memoized_fn>
2021-06-25T15:14:01.0902470Z tor = u'tor'
2021-06-25T15:14:01.0902700Z 
2021-06-25T15:14:01.0903890Z  /var/folders/24/8k48jl6d249_n_qfxwsl6xvm0000gn/T/tahoeK4n4lf/chutney/lib/chutney/Util.py in memoized_fn(*args=(u'tor',), **kwargs={})
2021-06-25T15:14:01.0904700Z    12             result = memory[key]
2021-06-25T15:14:01.0905160Z    13         except KeyError:
2021-06-25T15:14:01.0905660Z    14             result = memory[key] = fn(*args, **kwargs)
2021-06-25T15:14:01.0906170Z    15         return result
2021-06-25T15:14:01.0906580Z    16     return memoized_fn
2021-06-25T15:14:01.0907400Z result undefined
2021-06-25T15:14:01.0907800Z memory = {}
2021-06-25T15:14:01.0908680Z key = ((u'tor',), ())
2021-06-25T15:14:01.0909340Z fn = <function get_tor_version>
2021-06-25T15:14:01.0910120Z args = (u'tor',)
2021-06-25T15:14:01.0910540Z kwargs = {}
2021-06-25T15:14:01.0910790Z 
2021-06-25T15:14:01.0912000Z  /private/var/folders/24/8k48jl6d249_n_qfxwsl6xvm0000gn/T/tahoeK4n4lf/chutney/lib/chutney/TorNet.py in get_tor_version(tor=u'tor')
2021-06-25T15:14:01.0912880Z   353     tor_version = tor_version.replace(").", ")")
2021-06-25T15:14:01.0913530Z   354     # check we received a tor version, and nothing else
2021-06-25T15:14:01.0914530Z   355     assert re.match(r'^[-+.() A-Za-z0-9]+$', tor_version)
2021-06-25T15:14:01.0914970Z   356 
2021-06-25T15:14:01.0915370Z   357     return tor_version
2021-06-25T15:14:01.0916420Z global re = <module 're' from '/Users/runner/hostedtoolcache/Python/2.7.18/x64/lib/python2.7/re.pyc'>
2021-06-25T15:14:01.0917840Z re.match = <function match>
2021-06-25T15:14:01.0919050Z tor_version = u'Tor 0.4.6.5.\nTor is running on Darwin with Li...own N/A as libc.\nTor compiled with clang 12.0.0'
2021-06-25T15:14:01.0920190Z <type 'exceptions.AssertionError'>: 
2021-06-25T15:14:01.0921270Z     __class__ = <type 'exceptions.AssertionError'>
2021-06-25T15:14:01.0922520Z     __delattr__ = <method-wrapper '__delattr__' of exceptions.AssertionError object>
2021-06-25T15:14:01.0923200Z     __dict__ = {}
2021-06-25T15:14:01.0923930Z     __doc__ = 'Assertion failed.'
2021-06-25T15:14:01.0925050Z     __format__ = <built-in method __format__ of exceptions.AssertionError object>
2021-06-25T15:14:01.0926480Z     __getattribute__ = <method-wrapper '__getattribute__' of exceptions.AssertionError object>
2021-06-25T15:14:01.0927940Z     __getitem__ = <method-wrapper '__getitem__' of exceptions.AssertionError object>
2021-06-25T15:14:01.0929440Z     __getslice__ = <method-wrapper '__getslice__' of exceptions.AssertionError object>
2021-06-25T15:14:01.0930840Z     __hash__ = <method-wrapper '__hash__' of exceptions.AssertionError object>
2021-06-25T15:14:01.0932150Z     __init__ = <method-wrapper '__init__' of exceptions.AssertionError object>
2021-06-25T15:14:01.0933230Z     __new__ = <built-in method __new__ of type object>
2021-06-25T15:14:01.0934350Z     __reduce__ = <built-in method __reduce__ of exceptions.AssertionError object>
2021-06-25T15:14:01.0935690Z     __reduce_ex__ = <built-in method __reduce_ex__ of exceptions.AssertionError object>
2021-06-25T15:14:01.0937010Z     __repr__ = <method-wrapper '__repr__' of exceptions.AssertionError object>
2021-06-25T15:14:01.0939120Z     __setattr__ = <method-wrapper '__setattr__' of exceptions.AssertionError object>
2021-06-25T15:14:01.0941510Z     __setstate__ = <built-in method __setstate__ of exceptions.AssertionError object>
2021-06-25T15:14:01.0944000Z     __sizeof__ = <built-in method __sizeof__ of exceptions.AssertionError object>
2021-06-25T15:14:01.0945370Z     __str__ = <method-wrapper '__str__' of exceptions.AssertionError object>
2021-06-25T15:14:01.0946580Z     __subclasshook__ = <built-in method __subclasshook__ of type object>
2021-06-25T15:14:01.0947790Z     __unicode__ = <built-in method __unicode__ of exceptions.AssertionError object>
2021-06-25T15:14:01.0948440Z     args = ()
2021-06-25T15:14:01.0949100Z     message = ''
2021-06-25T15:14:01.0949350Z 
2021-06-25T15:14:01.0949840Z The above is a description of an error in a Python program.  Here is
2021-06-25T15:14:01.0950420Z the original traceback:
2021-06-25T15:14:01.0950700Z 
2021-06-25T15:14:01.0951070Z Traceback (most recent call last):
2021-06-25T15:14:01.0953710Z   File "/Users/runner/hostedtoolcache/Python/2.7.18/x64/lib/python2.7/runpy.py", line 174, in _run_module_as_main
2021-06-25T15:14:01.0954560Z     "__main__", fname, loader, pkg_name)
2021-06-25T15:14:01.0955350Z   File "/Users/runner/hostedtoolcache/Python/2.7.18/x64/lib/python2.7/runpy.py", line 72, in _run_code
2021-06-25T15:14:01.0956020Z     exec code in run_globals
2021-06-25T15:14:01.0956830Z   File "/private/var/folders/24/8k48jl6d249_n_qfxwsl6xvm0000gn/T/tahoeK4n4lf/chutney/lib/chutney/TorNet.py", line 2737, in <module>
2021-06-25T15:14:01.0957570Z     sys.exit(main())
2021-06-25T15:14:01.0958330Z   File "/private/var/folders/24/8k48jl6d249_n_qfxwsl6xvm0000gn/T/tahoeK4n4lf/chutney/lib/chutney/TorNet.py", line 2731, in main
2021-06-25T15:14:01.0959660Z     result = runConfigFile(args['action'], f.read())
2021-06-25T15:14:01.0960610Z   File "/private/var/folders/24/8k48jl6d249_n_qfxwsl6xvm0000gn/T/tahoeK4n4lf/chutney/lib/chutney/TorNet.py", line 2711, in runConfigFile
2021-06-25T15:14:01.0961430Z     return getattr(network, verb)()
2021-06-25T15:14:01.0962600Z   File "/private/var/folders/24/8k48jl6d249_n_qfxwsl6xvm0000gn/T/tahoeK4n4lf/chutney/lib/chutney/TorNet.py", line 2325, in configure
2021-06-25T15:14:01.0963680Z     b.config(network)
2021-06-25T15:14:01.0964900Z   File "/private/var/folders/24/8k48jl6d249_n_qfxwsl6xvm0000gn/T/tahoeK4n4lf/chutney/lib/chutney/TorNet.py", line 693, in config
2021-06-25T15:14:01.0965740Z     self._createTorrcFile()
2021-06-25T15:14:01.0966660Z   File "/private/var/folders/24/8k48jl6d249_n_qfxwsl6xvm0000gn/T/tahoeK4n4lf/chutney/lib/chutney/TorNet.py", line 630, in _createTorrcFile
2021-06-25T15:14:01.0967510Z     tor_version = get_tor_version(tor)
2021-06-25T15:14:01.0968310Z   File "/var/folders/24/8k48jl6d249_n_qfxwsl6xvm0000gn/T/tahoeK4n4lf/chutney/lib/chutney/Util.py", line 14, in memoized_fn
2021-06-25T15:14:01.0969090Z     result = memory[key] = fn(*args, **kwargs)
2021-06-25T15:14:01.0969950Z   File "/private/var/folders/24/8k48jl6d249_n_qfxwsl6xvm0000gn/T/tahoeK4n4lf/chutney/lib/chutney/TorNet.py", line 355, in get_tor_version
2021-06-25T15:14:01.0971440Z     assert re.match(r'^[-+.() A-Za-z0-9]+$', tor_version)
2021-06-25T15:14:01.0972250Z AssertionError

Change History (3)

comment:1 Changed at 2021-07-05T01:04:58Z by sajith

Pretty sure this is because of Tor 0.4.6.6.

Get the specific revision of chutney:

$ git clone https://git.torproject.org/chutney.git
Cloning into 'chutney'...
remote: Enumerating objects: 1696, done.
remote: Counting objects: 100% (1696/1696), done.
remote: Compressing objects: 100% (1451/1451), done.
remote: Total 3010 (delta 1056), reused 111 (delta 73)
Receiving objects: 100% (3010/3010), 671.92 KiB | 1.80 MiB/s, done.
Resolving deltas: 100% (1874/1874), done.
$ cd chutney
$ export PYTHONPATH=$PYTHONPATH:`pwd`/lib
$ git reset --hard 99bd06c7554b9113af8c0877b6eca4ceb95dcbaa

Run chutney configure command, which fails (this example shows Python 2.7, but it will also fail with Python 3):

$ python2.7 -m chutney.TorNet configure `pwd`/networks/basic
NOTE: creating u'/Users/sajith/projects/tahoe/chutney/net/nodes.1625446580', linking to u'/Users/sajith/projects/tahoe/chutney/net/nodes'
Creating identity key for test000a     with tor-gencert
Creating identity key for test001a     with tor-gencert
Creating identity key for test002a     with tor-gencert
<type 'exceptions.AssertionError'>
Python 2.7.17: /usr/local/opt/python@2/bin/python2.7
Sun Jul  4 20:56:22 2021

A problem occurred in a Python script.  Here is the sequence of
function calls leading up to the error, in the order they occurred.

 /usr/local/Cellar/python@2/2.7.17_1/Frameworks/Python.framework/Versions/2.7/lib/python2.7/runpy.py in _run_module_as_main(mod_name='chutney.TorNet', alter_argv=1)
  172         sys.argv[0] = fname
  173     return _run_code(code, main_globals, None,
  174                      "__main__", fname, loader, pkg_name)
  175
  176 def run_module(mod_name, init_globals=None,
fname = '/Users/sajith/projects/tahoe/chutney/lib/chutney/TorNet.py'
loader = <pkgutil.ImpLoader instance>
pkg_name = 'chutney'

 /usr/local/Cellar/python@2/2.7.17_1/Frameworks/Python.framework/Versions/2.7/lib/python2.7/runpy.py in _run_code(code=<code object <module> at 0x10e8f0230, file "/Use...ts/tahoe/chutney/lib/chutney/TorNet.py", line 11>, run_globals={'ConfigureNodes': <function ConfigureNodes>, 'DEFAULTS': {u'CUR_BOOTSTRAP_PHASE': 1, u'CUR_CONFIG_PHASE': 1, u'CUR_LAUNCH_PHASE': 1, u'auth_cert_lifetime': 12, u'authorities': u'AlternateDirAuthority bleargh bad torrc file!', u'authority': False, u'bootstrap_time': 60, u'bridge': False, u'bridgeauthority': False, u'bridges': u'Bridge bleargh bad torrc file!', ...}, 'KNOWN_REQUIREMENTS': {u'IPV6': <function memoized_fn>}, 'LocalNodeBuilder': <class '__main__.LocalNodeBuilder'>, 'LocalNodeController': <class '__main__.LocalNodeController'>, 'MissingBinaryException': <class '__main__.MissingBinaryException'>, 'Network': <class '__main__.Network'>, 'Node': <class '__main__.Node'>, 'NodeBuilder': <class '__main__.NodeBuilder'>, 'NodeController': <class '__main__.NodeController'>, ...}, init_globals=None, mod_name='__main__', mod_fname='/Users/sajith/projects/tahoe/chutney/lib/chutney/TorNet.py', mod_loader=<pkgutil.ImpLoader instance>, pkg_name='chutney')
   70                        __loader__ = mod_loader,
   71                        __package__ = pkg_name)
   72     exec code in run_globals
   73     return run_globals
   74
code = <code object <module> at 0x10e8f0230, file "/Use...ts/tahoe/chutney/lib/chutney/TorNet.py", line 11>
run_globals = {'ConfigureNodes': <function ConfigureNodes>, 'DEFAULTS': {u'CUR_BOOTSTRAP_PHASE': 1, u'CUR_CONFIG_PHASE': 1, u'CUR_LAUNCH_PHASE': 1, u'auth_cert_lifetime': 12, u'authorities': u'AlternateDirAuthority bleargh bad torrc file!', u'authority': False, u'bootstrap_time': 60, u'bridge': False, u'bridgeauthority': False, u'bridges': u'Bridge bleargh bad torrc file!', ...}, 'KNOWN_REQUIREMENTS': {u'IPV6': <function memoized_fn>}, 'LocalNodeBuilder': <class '__main__.LocalNodeBuilder'>, 'LocalNodeController': <class '__main__.LocalNodeController'>, 'MissingBinaryException': <class '__main__.MissingBinaryException'>, 'Network': <class '__main__.Network'>, 'Node': <class '__main__.Node'>, 'NodeBuilder': <class '__main__.NodeBuilder'>, 'NodeController': <class '__main__.NodeController'>, ...}

 /Users/sajith/projects/tahoe/chutney/lib/chutney/TorNet.py in <module>()
 2733         return -1
 2734     return 0
 2735
 2736 if __name__ == '__main__':
 2737     sys.exit(main())
sys = <module 'sys' (built-in)>
sys.exit = <built-in function exit>
main = <function main>

 /Users/sajith/projects/tahoe/chutney/lib/chutney/TorNet.py in main()
 2729     args = parseArgs()
 2730     f = open(args['network_cfg'])
 2731     result = runConfigFile(args['action'], f.read())
 2732     if result is False:
 2733         return -1
result undefined
global runConfigFile = <function runConfigFile>
args = {u'action': 'configure', u'network_cfg': '/Users/sajith/projects/tahoe/chutney/networks/basic'}
f = <open file '/Users/sajith/projects/tahoe/chutney/networks/basic', mode 'r'>
f.read = <built-in method read of file object>

 /Users/sajith/projects/tahoe/chutney/lib/chutney/TorNet.py in runConfigFile(verb='configure', data='# By default, Authorities are not configured as ....getN(5) + Client.getN(2)\n\nConfigureNodes(NODES)\n')
 2709         return
 2710
 2711     return getattr(network, verb)()
 2712
 2713
builtingetattr = <built-in function getattr>
network = <__main__.Network object>
verb = 'configure'

 /Users/sajith/projects/tahoe/chutney/lib/chutney/TorNet.py in configure(self=<__main__.Network object>)
 2323
 2324         for b in builders:
 2325             b.config(network)
 2326
 2327         for b in builders:
b = <__main__.LocalNodeBuilder object>
b.config = <bound method LocalNodeBuilder.config of <__main__.LocalNodeBuilder object>>
network = <__main__.Network object>

 /Users/sajith/projects/tahoe/chutney/lib/chutney/TorNet.py in config(self=<__main__.LocalNodeBuilder object>, net=<__main__.Network object>)
  691     def config(self, net):
  692         """Called to configure a node: creates a torrc file for it."""
  693         self._createTorrcFile()
  694         # self._createScripts()
  695
self = <__main__.LocalNodeBuilder object>
self._createTorrcFile = <bound method LocalNodeBuilder._createTorrcFile of <__main__.LocalNodeBuilder object>>

 /Users/sajith/projects/tahoe/chutney/lib/chutney/TorNet.py in _createTorrcFile(self=<__main__.LocalNodeBuilder object>, checkOnly=False)
  628         # the options that the current tor binary doesn't support
  629         tor = self._env['tor']
  630         tor_version = get_tor_version(tor)
  631         torrc_opts = get_torrc_options(tor)
  632         # check if each option is supported before writing it
tor_version undefined
global get_tor_version = <function memoized_fn>
tor = u'tor'

 /Users/sajith/projects/tahoe/chutney/lib/chutney/Util.py in memoized_fn(*args=(u'tor',), **kwargs={})
   12             result = memory[key]
   13         except KeyError:
   14             result = memory[key] = fn(*args, **kwargs)
   15         return result
   16     return memoized_fn
result undefined
memory = {}
key = ((u'tor',), ())
fn = <function get_tor_version>
args = (u'tor',)
kwargs = {}

 /Users/sajith/projects/tahoe/chutney/lib/chutney/TorNet.py in get_tor_version(tor=u'tor')
  353     tor_version = tor_version.replace(").", ")")
  354     # check we received a tor version, and nothing else
  355     assert re.match(r'^[-+.() A-Za-z0-9]+$', tor_version)
  356
  357     return tor_version
global re = <module 're' from '/usr/local/Cellar/python@2/2....hon.framework/Versions/2.7/lib/python2.7/re.pyc'>
re.match = <function match>
tor_version = u'Tor 0.4.6.6.\nTor is running on Darwin with Li...own N/A as libc.\nTor compiled with clang 12.0.5'
<type 'exceptions.AssertionError'>:
    __class__ = <type 'exceptions.AssertionError'>
    __delattr__ = <method-wrapper '__delattr__' of exceptions.AssertionError object>
    __dict__ = {}
    __doc__ = 'Assertion failed.'
    __format__ = <built-in method __format__ of exceptions.AssertionError object>
    __getattribute__ = <method-wrapper '__getattribute__' of exceptions.AssertionError object>
    __getitem__ = <method-wrapper '__getitem__' of exceptions.AssertionError object>
    __getslice__ = <method-wrapper '__getslice__' of exceptions.AssertionError object>
    __hash__ = <method-wrapper '__hash__' of exceptions.AssertionError object>
    __init__ = <method-wrapper '__init__' of exceptions.AssertionError object>
    __new__ = <built-in method __new__ of type object>
    __reduce__ = <built-in method __reduce__ of exceptions.AssertionError object>
    __reduce_ex__ = <built-in method __reduce_ex__ of exceptions.AssertionError object>
    __repr__ = <method-wrapper '__repr__' of exceptions.AssertionError object>
    __setattr__ = <method-wrapper '__setattr__' of exceptions.AssertionError object>
    __setstate__ = <built-in method __setstate__ of exceptions.AssertionError object>
    __sizeof__ = <built-in method __sizeof__ of exceptions.AssertionError object>
    __str__ = <method-wrapper '__str__' of exceptions.AssertionError object>
    __subclasshook__ = <built-in method __subclasshook__ of type object>
    __unicode__ = <built-in method __unicode__ of exceptions.AssertionError object>
    args = ()
    message = ''

The above is a description of an error in a Python program.  Here is
the original traceback:

Traceback (most recent call last):
  File "/usr/local/Cellar/python@2/2.7.17_1/Frameworks/Python.framework/Versions/2.7/lib/python2.7/runpy.py", line 174, in _run_module_as_main
    "__main__", fname, loader, pkg_name)
  File "/usr/local/Cellar/python@2/2.7.17_1/Frameworks/Python.framework/Versions/2.7/lib/python2.7/runpy.py", line 72, in _run_code
    exec code in run_globals
  File "/Users/sajith/projects/tahoe/chutney/lib/chutney/TorNet.py", line 2737, in <module>
    sys.exit(main())
  File "/Users/sajith/projects/tahoe/chutney/lib/chutney/TorNet.py", line 2731, in main
    result = runConfigFile(args['action'], f.read())
  File "/Users/sajith/projects/tahoe/chutney/lib/chutney/TorNet.py", line 2711, in runConfigFile
    return getattr(network, verb)()
  File "/Users/sajith/projects/tahoe/chutney/lib/chutney/TorNet.py", line 2325, in configure
    b.config(network)
  File "/Users/sajith/projects/tahoe/chutney/lib/chutney/TorNet.py", line 693, in config
    self._createTorrcFile()
  File "/Users/sajith/projects/tahoe/chutney/lib/chutney/TorNet.py", line 630, in _createTorrcFile
    tor_version = get_tor_version(tor)
  File "/Users/sajith/projects/tahoe/chutney/lib/chutney/Util.py", line 14, in memoized_fn
    result = memory[key] = fn(*args, **kwargs)
  File "/Users/sajith/projects/tahoe/chutney/lib/chutney/TorNet.py", line 355, in get_tor_version
    assert re.match(r'^[-+.() A-Za-z0-9]+$', tor_version)
AssertionError

comment:2 Changed at 2021-07-05T13:33:50Z by sajith

I could switch to the last known-to-work version of Tor from Homebrew this way:

$ brew extract --version 0.4.5.8 tor homebrew/cask
$ brew install tor@0.4.5.8
$ brew link --overwrite tor@0.4.5.8

To test, I checked out chutney commit 99bd06c7554b9113af8c0877b6eca4ceb95dcbaa, which is the last known chutney known to work with Python 2.7:

$ git clone https://git.torproject.org/chutney.git
Cloning into 'chutney'...
remote: Enumerating objects: 1696, done.
remote: Counting objects: 100% (1696/1696), done.
remote: Compressing objects: 100% (1451/1451), done.
remote: Total 3010 (delta 1056), reused 111 (delta 73)
Receiving objects: 100% (3010/3010), 697.42 KiB | 2.17 MiB/s, done.
Resolving deltas: 100% (1874/1874), done.
$ cd chutney; git reset --hard 99bd06c7554b9113af8c0877b6eca4ceb95dcbaa
HEAD is now at 99bd06c Merge remote-tracking branch 'tor-github/pr/66'
$ export PYTHONPATH=$PYTHONPATH:`pwd`/lib

Now chutney's configure command works the way it should:

$ python2.7 -m chutney.TorNet configure `pwd`/networks/basic
NOTE: creating u'/Users/sajith/chutney/net/nodes.1625491797', linking to u'/Users/sajith/chutney/net/nodes'
Creating identity key for test000a     with tor-gencert
Creating identity key for test001a     with tor-gencert
Creating identity key for test002a     with tor-gencert

Made a pull request: https://github.com/tahoe-lafs/tahoe-lafs/pull/1092.

Last edited at 2021-07-05T13:40:44Z by sajith (previous) (diff)

comment:3 Changed at 2021-07-05T17:27:13Z by sajith

  • Resolution set to fixed
  • Status changed from new to closed
Note: See TracTickets for help on using tickets.