Bitmask GUI hangs - terminal says "Already logged in"
Client used: Linux 0.3.2 64-bit on Ubuntu 13.04 with local vagrant nodes. Sometimes after logging out and logging in again the Bitmask GUI hangs on attempting to log in, and the terminal outputs "Already logged in", as in this run:
~/Downloads/Leap/Bitmask-linux64-0.3.2$ ./bitmask -d --danger
No updates found
2013-09-19 16:07:17,780 - leap - DEBUG - Console handler plugged!
2013-09-19 16:07:17,780 - leap - DEBUG - Leap handler plugged!
2013-09-19 16:07:17,781 - leap - DEBUG - Setting logfile to bitmask.log
2013-09-19 16:07:17,781 - leap - DEBUG - File handler plugged!
2013-09-19 16:07:17,781 - leap - DEBUG - 2013-09-19 16:07:17+0300 [-] Log opened.
2013-09-19 16:07:17,826 - leap.bitmask.util.requirement_checker - DEBUG - Checking requirements...
2013-09-19 16:07:17,853 - leap.bitmask.util.requirement_checker - ERROR - Requirements file not found. DistributionNotFound(Requirement.parse('leap.bitmask'),)
2013-09-19 16:07:17,853 - leap.bitmask.util.requirement_checker - DEBUG - Done
2013-09-19 16:07:17,854 - leap - INFO - ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
2013-09-19 16:07:17,854 - leap - INFO - Bitmask version 0.3.2
2013-09-19 16:07:17,854 - leap - INFO - ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
2013-09-19 16:07:17,854 - leap - INFO - Starting app
2013-09-19 16:07:17,993 - leap - DEBUG - Qt4 reactor installed
2013-09-19 16:07:18,225 - leap.bitmask.platform_init.initializers - DEBUG - Running initializer for Linux
2013-09-19 16:07:18,229 - leap.bitmask.gui.mainwindow - INFO - Cannot autostart Encrypted Internet because there is no default provider configured
2013-09-19 16:07:18,230 - leap.bitmask.gui.twisted_main - DEBUG - starting twisted reactor
2013-09-19 16:08:04,793 - leap.bitmask.services.eip.providerbootstrapper - DEBUG - Checking name resolution for bitmask.net
2013-09-19 16:08:04,817 - leap.bitmask.services.eip.providerbootstrapper - DEBUG - Checking https for bitmask.net
2013-09-19 16:08:04,884 - leap.bitmask.services.eip.providerbootstrapper - DEBUG - Downloading provider info for bitmask.net
2013-09-19 16:08:04,894 - leap.bitmask.config.providerconfig - DEBUG - Going to verify SSL against /home/thegrg/Downloads/Leap/Bitmask-linux64-0.3.2/config/leap/providers/bitmask.net/keys/ca/cacert.pem
2013-09-19 16:08:04,894 - leap.bitmask.services.eip.providerbootstrapper - DEBUG - Requesting for provider.json... uri: https://api.bitmask.net:4430/provider.json, verify: /home/thegrg/Downloads/Leap/Bitmask-linux64-0.3.2/config/leap/providers/bitmask.net/keys/ca/cacert.pem, headers: {'if-modified-since': 'Thu Sep 19 08:36:51 2013 GMT'}
2013-09-19 16:08:04,910 - leap.bitmask.services.eip.providerbootstrapper - DEBUG - Request status code: 304
2013-09-19 16:08:04,910 - leap.bitmask.services.eip.providerbootstrapper - DEBUG - Provider definition has not been modified
2013-09-19 16:08:04,927 - leap.bitmask.services.eip.providerbootstrapper - DEBUG - Downloading ca cert for bitmask.net at https://bitmask.net/ca.crt
2013-09-19 16:08:04,928 - leap.bitmask.config.providerconfig - DEBUG - Going to verify SSL against /home/thegrg/Downloads/Leap/Bitmask-linux64-0.3.2/config/leap/providers/bitmask.net/keys/ca/cacert.pem
2013-09-19 16:08:04,929 - leap.bitmask.services.eip.providerbootstrapper - DEBUG - Checking ca fingerprint for bitmask.net and cert /home/thegrg/Downloads/Leap/Bitmask-linux64-0.3.2/config/leap/providers/bitmask.net/keys/ca/cacert.pem
2013-09-19 16:08:04,930 - leap.bitmask.config.providerconfig - DEBUG - Going to verify SSL against /home/thegrg/Downloads/Leap/Bitmask-linux64-0.3.2/config/leap/providers/bitmask.net/keys/ca/cacert.pem
2013-09-19 16:08:04,931 - leap.bitmask.services.eip.providerbootstrapper - DEBUG - Checking api certificate for https://api.bitmask.net:4430 and cert /home/thegrg/Downloads/Leap/Bitmask-linux64-0.3.2/config/leap/providers/bitmask.net/keys/ca/cacert.pem
2013-09-19 16:08:04,931 - leap.bitmask.crypto.srpauth - DEBUG - Authentication preprocessing...
2013-09-19 16:08:04,932 - leap.bitmask.crypto.srpauth - DEBUG - Starting authentication process...
2013-09-19 16:08:04,933 - leap.bitmask.config.providerconfig - DEBUG - Going to verify SSL against /home/thegrg/Downloads/Leap/Bitmask-linux64-0.3.2/config/leap/providers/bitmask.net/keys/ca/cacert.pem
2013-09-19 16:08:05,054 - leap.bitmask.crypto.srpauth - DEBUG - Processing challenge...
2013-09-19 16:08:05,058 - leap.bitmask.config.providerconfig - DEBUG - Going to verify SSL against /home/thegrg/Downloads/Leap/Bitmask-linux64-0.3.2/config/leap/providers/bitmask.net/keys/ca/cacert.pem
2013-09-19 16:08:05,200 - leap.bitmask.crypto.srpauth - DEBUG - Verifying session...
2013-09-19 16:08:05,201 - leap.bitmask.crypto.srpauth - DEBUG - Session verified.
2013-09-19 16:08:05,207 - leap.bitmask.crypto.srpauth - DEBUG - Successful login!
2013-09-19 16:08:06,222 - leap.bitmask.services.soledad.soledadbootstrapper - DEBUG - Downloading Soledad config for bitmask.net
2013-09-19 16:08:06,223 - leap.bitmask.services.soledad.soledadbootstrapper - DEBUG - Downloading soledad config from: https://api.bitmask.net:4430/1/config/soledad-service.json
2013-09-19 16:08:06,226 - leap.bitmask.config.providerconfig - DEBUG - Going to verify SSL against /home/thegrg/Downloads/Leap/Bitmask-linux64-0.3.2/config/leap/providers/bitmask.net/keys/ca/cacert.pem
2013-09-19 16:08:06,259 - leap.bitmask.services.soledad.soledadbootstrapper - DEBUG - Soledad definition has not been modified
2013-09-19 16:08:06,269 - leap.bitmask.gui.mainwindow - ERROR - Soledad failed to start: No soledad server found
2013-09-19 16:08:06,270 - leap.bitmask.gui.mainwindow - DEBUG - Retrying soledad connection.
2013-09-19 16:08:06,270 - leap.bitmask.services.soledad.soledadbootstrapper - DEBUG - current retries: 0, max retries: 10
2013-09-19 16:08:06,272 - leap - DEBUG - 2013-09-19 16:08:06+0300 [-] Unhandled error in Deferred:
2013-09-19 16:08:06,275 - leap - DEBUG - 2013-09-19 16:08:06+0300 [-] Unhandled Error
2013-09-19 16:08:06,275 - leap - DEBUG - Traceback (most recent call last):
2013-09-19 16:08:06,276 - leap - DEBUG - File "/home/thegrg/Downloads/Leap/Bitmask-linux64-0.3.2/lib/threading.py", line 524, in __bootstrap
2013-09-19 16:08:06,276 - leap - DEBUG - self.__bootstrap_inner()
2013-09-19 16:08:06,277 - leap - DEBUG - File "/home/thegrg/Downloads/Leap/Bitmask-linux64-0.3.2/lib/threading.py", line 551, in __bootstrap_inner
2013-09-19 16:08:06,277 - leap - DEBUG - self.run()
2013-09-19 16:08:06,277 - leap - DEBUG - File "/home/thegrg/Downloads/Leap/Bitmask-linux64-0.3.2/lib/threading.py", line 504, in run
2013-09-19 16:08:06,278 - leap - DEBUG - self.__target(*self.__args, **self.__kwargs)
2013-09-19 16:08:06,279 - leap - DEBUG - --- ---
2013-09-19 16:08:06,279 - leap - DEBUG - File "/home/thegrg/Downloads/Leap/Bitmask-linux64-0.3.2/lib/twisted/python/threadpool.py", line 172, in _worker
2013-09-19 16:08:06,279 - leap - DEBUG - result = context.call(ctx, function, *args, **kwargs)
2013-09-19 16:08:06,280 - leap - DEBUG - File "/home/thegrg/Downloads/Leap/Bitmask-linux64-0.3.2/lib/twisted/python/context.py", line 118, in callWithContext
2013-09-19 16:08:06,280 - leap - DEBUG - return self.currentContext().callWithContext(ctx, func, *args, **kw)
2013-09-19 16:08:06,281 - leap - DEBUG - File "/home/thegrg/Downloads/Leap/Bitmask-linux64-0.3.2/lib/twisted/python/context.py", line 81, in callWithContext
2013-09-19 16:08:06,281 - leap - DEBUG - return func(*args,**kw)
2013-09-19 16:08:06,282 - leap - DEBUG - File "/home/thegrg/Downloads/Leap/Bitmask-linux64-0.3.2/apps/leap/bitmask/services/soledad/soledadbootstrapper.py", line 172, in load_and_sync_soledad
2013-09-19 16:08:06,282 - leap - DEBUG - raise Exception("No soledad server found")
2013-09-19 16:08:06,282 - leap - DEBUG - exceptions.Exception: No soledad server found
2013-09-19 16:08:15,220 - leap.bitmask.crypto.srpauth - DEBUG - Starting logout...
2013-09-19 16:08:15,221 - leap.bitmask.config.providerconfig - DEBUG - Going to verify SSL against /home/thegrg/Downloads/Leap/Bitmask-linux64-0.3.2/config/leap/providers/bitmask.net/keys/ca/cacert.pem
2013-09-19 16:08:15,302 - leap.bitmask.crypto.srpauth - WARNING - Something went wrong with the logout: ConnectionError(MaxRetryError("HTTPSConnectionPool(host='api.bitmask.net', port=4430): Max retries exceeded with url: /1/logout/ (Caused by : '')",),)
2013-09-19 16:08:20,411 - leap.bitmask.services.eip.providerbootstrapper - DEBUG - Checking name resolution for bitmask.net
2013-09-19 16:08:20,416 - leap.bitmask.services.eip.providerbootstrapper - DEBUG - Checking https for bitmask.net
2013-09-19 16:08:20,503 - leap.bitmask.services.eip.providerbootstrapper - DEBUG - Downloading provider info for bitmask.net
2013-09-19 16:08:20,517 - leap.bitmask.config.providerconfig - DEBUG - Going to verify SSL against /home/thegrg/Downloads/Leap/Bitmask-linux64-0.3.2/config/leap/providers/bitmask.net/keys/ca/cacert.pem
2013-09-19 16:08:20,517 - leap.bitmask.services.eip.providerbootstrapper - DEBUG - Requesting for provider.json... uri: https://api.bitmask.net:4430/provider.json, verify: /home/thegrg/Downloads/Leap/Bitmask-linux64-0.3.2/config/leap/providers/bitmask.net/keys/ca/cacert.pem, headers: {'if-modified-since': 'Thu Sep 19 08:36:51 2013 GMT'}
2013-09-19 16:08:20,538 - leap.bitmask.services.eip.providerbootstrapper - DEBUG - Request status code: 304
2013-09-19 16:08:20,538 - leap.bitmask.services.eip.providerbootstrapper - DEBUG - Provider definition has not been modified
2013-09-19 16:08:20,540 - leap.bitmask.services.eip.providerbootstrapper - DEBUG - Downloading ca cert for bitmask.net at https://bitmask.net/ca.crt
2013-09-19 16:08:20,542 - leap.bitmask.config.providerconfig - DEBUG - Going to verify SSL against /home/thegrg/Downloads/Leap/Bitmask-linux64-0.3.2/config/leap/providers/bitmask.net/keys/ca/cacert.pem
2013-09-19 16:08:20,542 - leap.bitmask.services.eip.providerbootstrapper - DEBUG - Checking ca fingerprint for bitmask.net and cert /home/thegrg/Downloads/Leap/Bitmask-linux64-0.3.2/config/leap/providers/bitmask.net/keys/ca/cacert.pem
2013-09-19 16:08:20,544 - leap.bitmask.config.providerconfig - DEBUG - Going to verify SSL against /home/thegrg/Downloads/Leap/Bitmask-linux64-0.3.2/config/leap/providers/bitmask.net/keys/ca/cacert.pem
2013-09-19 16:08:20,545 - leap.bitmask.services.eip.providerbootstrapper - DEBUG - Checking api certificate for https://api.bitmask.net:4430 and cert /home/thegrg/Downloads/Leap/Bitmask-linux64-0.3.2/config/leap/providers/bitmask.net/keys/ca/cacert.pem
2013-09-19 16:08:20,546 - leap.common.check - ERROR - Bug: Already logged in
2013-09-19 16:08:20,550 - leap.common.check - ERROR - File "apps/launcher.py", line 65, in
2013-09-19 16:08:20,551 - leap.common.check - ERROR - leap_client()
2013-09-19 16:08:20,551 - leap.common.check - ERROR - File "/home/thegrg/Downloads/Leap/Bitmask-linux64-0.3.2/apps/leap/bitmask/app.py", line 242, in main
2013-09-19 16:08:20,551 - leap.common.check - ERROR - twisted_main.start(app)
2013-09-19 16:08:20,551 - leap.common.check - ERROR - File "/home/thegrg/Downloads/Leap/Bitmask-linux64-0.3.2/apps/leap/bitmask/gui/twisted_main.py", line 45, in start
2013-09-19 16:08:20,551 - leap.common.check - ERROR - app.exec_()
2013-09-19 16:08:20,551 - leap.common.check - ERROR - File "/home/thegrg/Downloads/Leap/Bitmask-linux64-0.3.2/lib/qt4reactor.py", line 103, in read
2013-09-19 16:08:20,552 - leap.common.check - ERROR - log.callWithLogger(w, _read)
2013-09-19 16:08:20,552 - leap.common.check - ERROR - File "/home/thegrg/Downloads/Leap/Bitmask-linux64-0.3.2/lib/twisted/python/log.py", line 88, in callWithLogger
2013-09-19 16:08:20,552 - leap.common.check - ERROR - return callWithContext({"system": lp}, func, *args, **kw)
2013-09-19 16:08:20,552 - leap.common.check - ERROR - File "/home/thegrg/Downloads/Leap/Bitmask-linux64-0.3.2/lib/twisted/python/log.py", line 73, in callWithContext
2013-09-19 16:08:20,552 - leap.common.check - ERROR - return context.call({ILogContext: newCtx}, func, *args, **kw)
2013-09-19 16:08:20,552 - leap.common.check - ERROR - File "/home/thegrg/Downloads/Leap/Bitmask-linux64-0.3.2/lib/twisted/python/context.py", line 118, in callWithContext
2013-09-19 16:08:20,552 - leap.common.check - ERROR - return self.currentContext().callWithContext(ctx, func, *args, **kw)
2013-09-19 16:08:20,553 - leap.common.check - ERROR - File "/home/thegrg/Downloads/Leap/Bitmask-linux64-0.3.2/lib/twisted/python/context.py", line 81, in callWithContext
2013-09-19 16:08:20,553 - leap.common.check - ERROR - return func(*args,**kw)
2013-09-19 16:08:20,553 - leap.common.check - ERROR - File "/home/thegrg/Downloads/Leap/Bitmask-linux64-0.3.2/lib/qt4reactor.py", line 102, in _read
2013-09-19 16:08:20,553 - leap.common.check - ERROR - self.reactor._iterate(fromqt=True)
2013-09-19 16:08:20,553 - leap.common.check - ERROR - File "/home/thegrg/Downloads/Leap/Bitmask-linux64-0.3.2/lib/qt4reactor.py", line 231, in _iterate
2013-09-19 16:08:20,553 - leap.common.check - ERROR - self.runUntilCurrent()
2013-09-19 16:08:20,553 - leap.common.check - ERROR - File "/home/thegrg/Downloads/Leap/Bitmask-linux64-0.3.2/lib/twisted/internet/base.py", line 797, in runUntilCurrent
2013-09-19 16:08:20,554 - leap.common.check - ERROR - f(*a, **kw)
2013-09-19 16:08:20,554 - leap.common.check - ERROR - File "/home/thegrg/Downloads/Leap/Bitmask-linux64-0.3.2/lib/twisted/internet/defer.py", line 380, in callback
2013-09-19 16:08:20,554 - leap.common.check - ERROR - self._startRunCallbacks(result)
2013-09-19 16:08:20,554 - leap.common.check - ERROR - File "/home/thegrg/Downloads/Leap/Bitmask-linux64-0.3.2/lib/twisted/internet/defer.py", line 488, in _startRunCallbacks
2013-09-19 16:08:20,554 - leap.common.check - ERROR - self._runCallbacks()
2013-09-19 16:08:20,554 - leap.common.check - ERROR - File "/home/thegrg/Downloads/Leap/Bitmask-linux64-0.3.2/lib/twisted/internet/defer.py", line 575, in _runCallbacks
2013-09-19 16:08:20,554 - leap.common.check - ERROR - current.result = callback(current.result, *args, **kw)
2013-09-19 16:08:20,555 - leap.common.check - ERROR - File "/home/thegrg/Downloads/Leap/Bitmask-linux64-0.3.2/apps/leap/bitmask/services/abstractbootstrapper.py", line 131, in _gui_notify
2013-09-19 16:08:20,555 - leap.common.check - ERROR - signal.emit({self.PASSED_KEY: True, self.ERROR_KEY: ""})
2013-09-19 16:08:20,555 - leap.common.check - ERROR - File "/home/thegrg/Downloads/Leap/Bitmask-linux64-0.3.2/apps/leap/bitmask/gui/mainwindow.py", line 926, in _provider_config_loaded
2013-09-19 16:08:20,555 - leap.common.check - ERROR - self._login_defer = self._srp_auth.authenticate(username, password)
2013-09-19 16:08:20,555 - leap.common.check - ERROR - File "/home/thegrg/Downloads/Leap/Bitmask-linux64-0.3.2/apps/leap/bitmask/crypto/srpauth.py", line 618, in authenticate
2013-09-19 16:08:20,555 - leap.common.check - ERROR - d = self.__instance.authenticate(username, password)
2013-09-19 16:08:20,555 - leap.common.check - ERROR - File "/home/thegrg/Downloads/Leap/Bitmask-linux64-0.3.2/apps/leap/bitmask/crypto/srpauth.py", line 506, in authenticate
2013-09-19 16:08:20,555 - leap.common.check - ERROR - leap_assert(self.get_session_id() is None, "Already logged in")
2013-09-19 16:08:20,556 - leap - DEBUG - 2013-09-19 16:08:20+0300 [-] Traceback (most recent call last):
2013-09-19 16:08:20,556 - leap - DEBUG - 2013-09-19 16:08:20+0300 [-] File "/home/thegrg/Downloads/Leap/Bitmask-linux64-0.3.2/apps/leap/bitmask/gui/mainwindow.py", line 926, in _provider_config_loaded
2013-09-19 16:08:20,556 - leap - DEBUG - 2013-09-19 16:08:20+0300 [-] self._login_defer = self._srp_auth.authenticate(username, password)
2013-09-19 16:08:20,556 - leap - DEBUG - 2013-09-19 16:08:20+0300 [-] File "/home/thegrg/Downloads/Leap/Bitmask-linux64-0.3.2/apps/leap/bitmask/crypto/srpauth.py", line 618, in authenticate
2013-09-19 16:08:20,556 - leap - DEBUG - 2013-09-19 16:08:20+0300 [-] d = self.__instance.authenticate(username, password)
2013-09-19 16:08:20,557 - leap - DEBUG - 2013-09-19 16:08:20+0300 [-] File "/home/thegrg/Downloads/Leap/Bitmask-linux64-0.3.2/apps/leap/bitmask/crypto/srpauth.py", line 506, in authenticate
2013-09-19 16:08:20,557 - leap - DEBUG - 2013-09-19 16:08:20+0300 [-] leap_assert(self.get_session_id() is None, "Already logged in")
2013-09-19 16:08:20,557 - leap - DEBUG - 2013-09-19 16:08:20+0300 [-] File "/home/thegrg/Downloads/Leap/Bitmask-linux64-0.3.2/lib/leap/common/check.py", line 48, in leap_assert
2013-09-19 16:08:20,557 - leap - DEBUG - 2013-09-19 16:08:20+0300 [-] assert condition, message
2013-09-19 16:08:20,557 - leap - DEBUG - 2013-09-19 16:08:20+0300 [-] AssertionError: Already logged in
(from redmine: created on 2013-09-19, closed on 2013-10-21, duplicates #3774 (closed))