Skip to content

Configuring new provider with 0.7.0~rc1 fails with traceback

I tried to configure a new provider with the debian packaged version of 0.7.0~rc1 and when I clicked 'check', I got red text under the check area that says "str returned non-string (type Error)". I ran it in debug mode and I see this:

2014-10-14 10:13:24,349 - DEBUG    - L#51   : leap:create_logger() - Console handler plugged!
2014-10-14 10:13:24,349 - DEBUG    - L#58   : leap:create_logger() - Leap handler plugged!
2014-10-14 10:13:24,350 - DEBUG    - L#53   : leap:write() - 2014-10-14 10:13:24-0400 [-] Log opened.
2014-10-14 10:13:24,360 - DEBUG    - L#72   : leap.bitmask.util.requirement_checker:check_requirements() - Checking requirements...
2014-10-14 10:13:24,361 - DEBUG    - L#100  : leap.bitmask.util.requirement_checker:check_requirements() - requests>=1.1.0 ... OK
2014-10-14 10:13:24,362 - DEBUG    - L#100  : leap.bitmask.util.requirement_checker:check_requirements() - srp>=1.0.2 ... OK
2014-10-14 10:13:24,362 - DEBUG    - L#100  : leap.bitmask.util.requirement_checker:check_requirements() - pyopenssl ... OK
2014-10-14 10:13:24,362 - DEBUG    - L#100  : leap.bitmask.util.requirement_checker:check_requirements() - python-dateutil  #==1.4  # See  https://leap.se/code/issues/6099 ... OK
2014-10-14 10:13:24,363 - DEBUG    - L#100  : leap.bitmask.util.requirement_checker:check_requirements() - psutil ... OK
2014-10-14 10:13:24,363 - DEBUG    - L#100  : leap.bitmask.util.requirement_checker:check_requirements() - ipaddr ... OK
2014-10-14 10:13:24,363 - DEBUG    - L#100  : leap.bitmask.util.requirement_checker:check_requirements() - python-daemon # this should not be needed for Windows. ... OK
2014-10-14 10:13:24,363 - DEBUG    - L#100  : leap.bitmask.util.requirement_checker:check_requirements() - keyring ... OK
2014-10-14 10:13:24,364 - DEBUG    - L#100  : leap.bitmask.util.requirement_checker:check_requirements() - zope.proxy ... OK
2014-10-14 10:13:24,364 - DEBUG    - L#100  : leap.bitmask.util.requirement_checker:check_requirements() - pyzmq ... OK
2014-10-14 10:13:24,364 - DEBUG    - L#100  : leap.bitmask.util.requirement_checker:check_requirements() - leap.common>=0.3.7 ... OK
2014-10-14 10:13:24,365 - DEBUG    - L#100  : leap.bitmask.util.requirement_checker:check_requirements() - leap.soledad.client>=0.5.0 ... OK
2014-10-14 10:13:24,365 - DEBUG    - L#100  : leap.bitmask.util.requirement_checker:check_requirements() - leap.keymanager>=0.3.8 ... OK
2014-10-14 10:13:24,365 - DEBUG    - L#100  : leap.bitmask.util.requirement_checker:check_requirements() - leap.mail>=0.3.9 ... OK
2014-10-14 10:13:24,365 - DEBUG    - L#100  : leap.bitmask.util.requirement_checker:check_requirements() - oauth ... OK
2014-10-14 10:13:24,366 - DEBUG    - L#102  : leap.bitmask.util.requirement_checker:check_requirements() - Done
2014-10-14 10:13:24,366 - INFO     - L#172  : leap:start_app() - ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
2014-10-14 10:13:24,366 - INFO     - L#173  : leap:start_app() - Bitmask version 0.7.0-rc1
2014-10-14 10:13:24,366 - INFO     - L#174  : leap:start_app() - leap.mail version 0.3.9
2014-10-14 10:13:24,367 - INFO     - L#175  : leap:start_app() - ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
2014-10-14 10:13:24,367 - INFO     - L#177  : leap:start_app() - Starting app
2014-10-14 10:13:24,389 - DEBUG    - L#49   : leap.bitmask.backend.signaler:__init__() - Connecting to signaling server...
2014-10-14 10:13:24,537 - DEBUG    - L#56   : leap.bitmask.backend.backend_proxy:__init__() - Connecting to server...
2014-10-14 10:13:24,539 - DEBUG    - L#66   : leap.bitmask.backend.signaler_qt:_run() - Running SignalerQt loop
2014-10-14 10:13:24,556 - DEBUG    - L#55   : leap.bitmask.util.keyring_helpers:_get_keyring_with_fallback() - Selected keyring: 
2014-10-14 10:13:24,572 - DEBUG    - L#55   : leap.bitmask.util.keyring_helpers:_get_keyring_with_fallback() - Selected keyring: 
2014-10-14 10:13:24,662 - DEBUG    - L#68   : leap.bitmask.platform_init.initializers:init_platform() - Running initializer for Linux
2014-10-14 10:13:24,687 - DEBUG    - L#111  : leap.bitmask.services.eip.conductor:start_eip_machine() - eip machine started
2014-10-14 10:13:24,687 - DEBUG    - L#239  : leap.bitmask.services.mail.conductor:start_mail_machine() - Starting mail state machine...
2014-10-14 10:13:24,713 - DEBUG    - L#59   : leap.bitmask.gui.statemachines:onEntry() - State Encrypted Internet::off entered. Emitting signal ...
2014-10-14 10:13:24,714 - DEBUG    - L#59   : leap.bitmask.gui.statemachines:onEntry() - State Mail::off entered. Emitting signal ...
2014-10-14 10:13:24,714 - DEBUG    - L#59   : leap.bitmask.gui.statemachines:onEntry() - State IMAP::off entered. Emitting signal ...
2014-10-14 10:13:24,715 - DEBUG    - L#59   : leap.bitmask.gui.statemachines:onEntry() - State IMAP::off entered. Emitting signal ...
2014-10-14 10:13:24,920 - DEBUG    - L#336  : leap.bitmask.gui.eip_status:enable_eip_start() - Showing EIP start button
2014-10-14 10:13:24,921 - DEBUG    - L#371  : leap.bitmask.gui.eip_status:set_eip_status() - 
2014-10-14 10:19:06,820 - DEBUG    - L#53   : leap:write() - 2014-10-14 10:19:06-0400 [-] Setting up provider dev.bitmask.net...
2014-10-14 10:19:06,821 - DEBUG    - L#120  : leap.bitmask.provider.providerbootstrapper:_check_name_resolution() - Checking name resolution for u'dev.bitmask.net'
2014-10-14 10:19:06,990 - DEBUG    - L#134  : leap.bitmask.provider.providerbootstrapper:_check_https() - Checking https for u'dev.bitmask.net'
2014-10-14 10:19:07,371 - DEBUG    - L#53   : leap:write() - 2014-10-14 10:19:07-0400 [-] Traceback (most recent call last):
2014-10-14 10:19:07,372 - DEBUG    - L#53   : leap:write() - 2014-10-14 10:19:07-0400 [-]   File "/usr/lib/python2.7/logging/__init__.py", line 859, in emit
2014-10-14 10:19:07,375 - DEBUG    - L#53   : leap:write() - 2014-10-14 10:19:07-0400 [-]     msg = self.format(record)
2014-10-14 10:19:07,375 - DEBUG    - L#53   : leap:write() - 2014-10-14 10:19:07-0400 [-]   File "/usr/lib/python2.7/logging/__init__.py", line 732, in format
2014-10-14 10:19:07,376 - DEBUG    - L#53   : leap:write() - 2014-10-14 10:19:07-0400 [-]     return fmt.format(record)
2014-10-14 10:19:07,376 - DEBUG    - L#53   : leap:write() - 2014-10-14 10:19:07-0400 [-]   File "/usr/lib/python2.7/logging/__init__.py", line 471, in format
2014-10-14 10:19:07,376 - DEBUG    - L#53   : leap:write() - 2014-10-14 10:19:07-0400 [-]     record.message = record.getMessage()
2014-10-14 10:19:07,377 - DEBUG    - L#53   : leap:write() - 2014-10-14 10:19:07-0400 [-]   File "/usr/lib/python2.7/logging/__init__.py", line 331, in getMessage
2014-10-14 10:19:07,377 - DEBUG    - L#53   : leap:write() - 2014-10-14 10:19:07-0400 [-]     msg = str(self.msg)
2014-10-14 10:19:07,377 - DEBUG    - L#53   : leap:write() - 2014-10-14 10:19:07-0400 [-] TypeError: __str__ returned non-string (type Error)
2014-10-14 10:19:07,378 - DEBUG    - L#53   : leap:write() - 2014-10-14 10:19:07-0400 [-] Logged from file providerbootstrapper.py, line 151
2014-10-14 10:19:07,383 - DEBUG    - L#53   : leap:write() - 2014-10-14 10:19:07-0400 [-] Unhandled Error
2014-10-14 10:19:07,384 - DEBUG    - L#53   : leap:write() - 	Traceback (most recent call last):
2014-10-14 10:19:07,384 - DEBUG    - L#53   : leap:write() - 	  File "/usr/lib/python2.7/threading.py", line 783, in __bootstrap
2014-10-14 10:19:07,384 - ERROR    - L#523  : leap.bitmask.gui.wizard:_complete_task() - __str__ returned non-string (type Error)
2014-10-14 10:19:07,384 - DEBUG    - L#53   : leap:write() - 	    self.__bootstrap_inner()
2014-10-14 10:19:07,384 - DEBUG    - L#53   : leap:write() - 	  File "/usr/lib/python2.7/threading.py", line 810, in __bootstrap_inner
2014-10-14 10:19:07,385 - DEBUG    - L#53   : leap:write() - 	    self.run()
2014-10-14 10:19:07,385 - DEBUG    - L#53   : leap:write() - 	  File "/usr/lib/python2.7/threading.py", line 763, in run
2014-10-14 10:19:07,385 - DEBUG    - L#53   : leap:write() - 	    self.__target(*self.__args, **self.__kwargs)
2014-10-14 10:19:07,385 - DEBUG    - L#53   : leap:write() - 	---  ---
2014-10-14 10:19:07,385 - DEBUG    - L#53   : leap:write() - 	  File "/usr/lib/python2.7/dist-packages/twisted/python/threadpool.py", line 196, in _worker
2014-10-14 10:19:07,385 - DEBUG    - L#53   : leap:write() - 	    result = context.call(ctx, function, *args, **kwargs)
2014-10-14 10:19:07,386 - DEBUG    - L#53   : leap:write() - 	  File "/usr/lib/python2.7/dist-packages/twisted/python/context.py", line 118, in callWithContext
2014-10-14 10:19:07,386 - DEBUG    - L#53   : leap:write() - 	    return self.currentContext().callWithContext(ctx, func, *args, **kw)
2014-10-14 10:19:07,386 - DEBUG    - L#53   : leap:write() - 	  File "/usr/lib/python2.7/dist-packages/twisted/python/context.py", line 81, in callWithContext
2014-10-14 10:19:07,387 - DEBUG    - L#53   : leap:write() - 	    return func(*args,**kw)
2014-10-14 10:19:07,387 - DEBUG    - L#53   : leap:write() - 	  File "/usr/lib/python2.7/dist-packages/leap/bitmask/provider/providerbootstrapper.py", line 151, in _check_https
2014-10-14 10:19:07,387 - DEBUG    - L#53   : leap:write() - 	    logger.exception(exc)
2014-10-14 10:19:07,387 - DEBUG    - L#53   : leap:write() - 	  File "/usr/lib/python2.7/logging/__init__.py", line 1193, in exception
2014-10-14 10:19:07,387 - DEBUG    - L#53   : leap:write() - 	    self.error(msg, *args, **kwargs)
2014-10-14 10:19:07,387 - DEBUG    - L#53   : leap:write() - 	  File "/usr/lib/python2.7/logging/__init__.py", line 1186, in error
2014-10-14 10:19:07,388 - DEBUG    - L#53   : leap:write() - 	    self._log(ERROR, msg, args, **kwargs)
2014-10-14 10:19:07,388 - DEBUG    - L#53   : leap:write() - 	  File "/usr/lib/python2.7/logging/__init__.py", line 1279, in _log
2014-10-14 10:19:07,388 - DEBUG    - L#53   : leap:write() - 	    self.handle(record)
2014-10-14 10:19:07,388 - DEBUG    - L#53   : leap:write() - 	  File "/usr/lib/python2.7/logging/__init__.py", line 1289, in handle
2014-10-14 10:19:07,389 - DEBUG    - L#53   : leap:write() - 	    self.callHandlers(record)
2014-10-14 10:19:07,389 - DEBUG    - L#53   : leap:write() - 	  File "/usr/lib/python2.7/logging/__init__.py", line 1329, in callHandlers
2014-10-14 10:19:07,389 - DEBUG    - L#53   : leap:write() - 	    hdlr.handle(record)
2014-10-14 10:19:07,389 - DEBUG    - L#53   : leap:write() - 	  File "/usr/lib/python2.7/dist-packages/leap/bitmask/logs/leap_log_handler.py", line 97, in handle
2014-10-14 10:19:07,390 - DEBUG    - L#53   : leap:write() - 	    return self._handler.handle(*args, **kwargs)
2014-10-14 10:19:07,390 - DEBUG    - L#53   : leap:write() - 	  File "/usr/lib/python2.7/logging/__init__.py", line 757, in handle
2014-10-14 10:19:07,390 - DEBUG    - L#53   : leap:write() - 	    self.emit(record)
2014-10-14 10:19:07,390 - DEBUG    - L#53   : leap:write() - 	  File "/usr/lib/python2.7/dist-packages/leap/bitmask/logs/leap_log_handler.py", line 71, in emit
2014-10-14 10:19:07,390 - DEBUG    - L#53   : leap:write() - 	    log = self.format(logRecord)
2014-10-14 10:19:07,391 - DEBUG    - L#53   : leap:write() - 	  File "/usr/lib/python2.7/logging/__init__.py", line 732, in format
2014-10-14 10:19:07,391 - DEBUG    - L#53   : leap:write() - 	    return fmt.format(record)
2014-10-14 10:19:07,391 - DEBUG    - L#53   : leap:write() - 	  File "/usr/lib/python2.7/logging/__init__.py", line 471, in format
2014-10-14 10:19:07,391 - DEBUG    - L#53   : leap:write() - 	    record.message = record.getMessage()
2014-10-14 10:19:07,392 - DEBUG    - L#53   : leap:write() - 	  File "/usr/lib/python2.7/logging/__init__.py", line 331, in getMessage
2014-10-14 10:19:07,392 - DEBUG    - L#53   : leap:write() - 	    msg = str(self.msg)
2014-10-14 10:19:07,392 - DEBUG    - L#53   : leap:write() - 	exceptions.TypeError: __str__ returned non-string (type Error)

I dont know if this is a package issue, something wrong with the provider, or something else, but it seems like we should get a better error message there when things fail.

(from redmine: created on 2014-10-14, closed on 2014-11-26, relates #6376 (closed), duplicates #6295 (closed))