Bitmask client fails to upload GPG keys
Using:
- bitmask-dev: 1e6a435a
- soledad: a7ffb49e1169c93af3b728f5db1a5e16e6231590
- cdev env: with experimental-0.9 platform and beta soledad 0.9.0
Then I'm typing the following commands:
rm -rf ~/.config/leap/soledad/b2a386cd8f06dc89a0e13863895fb328.* bitmaskctl launch bitmaskctl user auth drebs@cdev.bitmask.net
Then I get the following log:
2016-09-12T14:27:15-0300 [-] Loading /home/drebs/dev/leap/repos/bitmask-dev/src/leap/bitmask/core/bitmaskd.tac... 2016-09-12T14:27:15-0300 [-] Loaded. 2016-09-12T14:27:15-0300 [twisted.scripts._twistd_unix.UnixAppLogger#info] twistd 16.3.0 (/home/drebs/.venv/bin/python2 2.7.9) starting up. 2016-09-12T14:27:15-0300 [twisted.scripts._twistd_unix.UnixAppLogger#info] reactor class: twisted.internet.epollreactor.EPollReactor. 2016-09-12T14:27:15-0300 [-] Starting Bonafide Service 2016-09-12T14:27:15-0300 [-] Registering hook on_passphrase_entry->soledad 2016-09-12T14:27:15-0300 [-] Registering hook on_bonafide_auth->soledad 2016-09-12T14:27:15-0300 [-] Registering hook on_bonafide_auth->keymanager 2016-09-12T14:27:15-0300 [-] Starting Soledad Service 2016-09-12T14:27:15-0300 [-] Registering hook on_new_soledad_instance->keymanager 2016-09-12T14:27:15-0300 [-] Starting Keymanager Service 2016-09-12T14:27:15-0300 [-] Registering hook on_new_keymanager_instance->mail 2016-09-12T14:27:15-0300 [-] LeapIMAPFactory starting on 1984 2016-09-12T14:27:15-0300 [leap.bitmask.mail.imap.service.imap.LeapIMAPFactory#info] Starting factory 2016-09-12T14:27:15-0300 [-] SMTPFactory starting on 2013 2016-09-12T14:27:15-0300 [leap.bitmask.mail.smtp.gateway.SMTPFactory#info] Starting factory 2016-09-12T14:27:15-0300 [-] Starting Mail Service... 2016-09-12T14:27:15-0300 [-] Starting IMAP Service 2016-09-12T14:27:15-0300 [-] Starting SMTP Service 2016-09-12T14:27:15-0300 [-] Starting IncomingMail Service 2016-09-12T14:27:15-0300 [-] starting ZMQ dispatcher 2016-09-12T14:27:15-0300 [-] Site starting on 7070 2016-09-12T14:27:15-0300 [twisted.web.server.Site#info] Starting factory 2016-09-12T14:27:25-0300 [ZMQ] Provider already initialized 2016-09-12T14:27:25-0300 [ZMQ] on_passphrase_entry: New Soledad Instance: drebs@cdev.bitmask.net 2016-09-12T14:27:26-0300 [ZMQ] Adding a new Keymanager instance for drebs@cdev.bitmask.net 2016-09-12T14:27:26-0300 [ZMQ] Provider already initialized 2016-09-12T14:27:26-0300 [ZMQ] AUTH for drebs@cdev.bitmask.net 2016-09-12T14:27:26-0300 [ZMQ] POST to https://api.cdev.bitmask.net:4430/1/sessions 2016-09-12T14:27:26-0300 [twisted.web.client._HTTP11ClientFactory#info] Starting factory 2016-09-12T14:27:26-0300 [-] Core: Key not found. Generating key for drebs@cdev.bitmask.net 2016-09-12T14:27:28-0300 [HTTP11ClientProtocol (TLSMemoryBIOProtocol),client] PUT to https://api.cdev.bitmask.net:4430/1/sessions/drebs 2016-09-12T14:27:28-0300 [twisted.web.client._HTTP11ClientFactory#info] Starting factory 2016-09-12T14:27:28-0300 [twisted.web.client._HTTP11ClientFactory#info] Stopping factory 2016-09-12T14:27:29-0300 [HTTP11ClientProtocol (TLSMemoryBIOProtocol),client] Provider already initialized 2016-09-12T14:27:29-0300 [HTTP11ClientProtocol (TLSMemoryBIOProtocol),client] Passing a new SRP Token to Soledad: drebs@cdev.bitmask.net 2016-09-12T14:27:30-0300 [HTTP11ClientProtocol (TLSMemoryBIOProtocol),client] Provider already initialized 2016-09-12T14:27:30-0300 [HTTP11ClientProtocol (TLSMemoryBIOProtocol),client] storing the keymanager token... fCBHGD5OPCgHx76xpd-P_GjVbDVQ6yNB41PZfBPBGvs 2016-09-12T14:27:30-0300 [twisted.web.client._HTTP11ClientFactory#info] Stopping factory 2016-09-12T14:27:40-0300 [-] 'Error while sending key!' 2016-09-12T14:27:40-0300 [-] Unhandled Error Traceback (most recent call last): File "/home/drebs/.venv/local/lib/python2.7/site-packages/twisted/internet/defer.py", line 501, in _startRunCallbacks self._runCallbacks() File "/home/drebs/.venv/local/lib/python2.7/site-packages/twisted/internet/defer.py", line 588, in _runCallbacks current.result = callback(current.result, *args, **kw) File "/home/drebs/dev/leap/repos/bitmask-dev/src/leap/bitmask/keymanager/__init__.py", line 321, in send d = self._put(uri, data) File "/home/drebs/.venv/local/lib/python2.7/site-packages/twisted/internet/defer.py", line 1274, in unwindGenerator return _inlineCallbacks(None, gen, Deferred()) --- --- File "/home/drebs/.venv/local/lib/python2.7/site-packages/twisted/internet/defer.py", line 1128, in _inlineCallbacks result = g.send(result) File "/home/drebs/dev/leap/repos/bitmask-dev/src/leap/bitmask/keymanager/__init__.py", line 245, in _put 'We need a token to interact with webapp!') File "/home/drebs/dev/leap/repos/leap_pycommon/src/leap/common/check.py", line 48, in leap_assert assert condition, message exceptions.AssertionError: We need a token to interact with webapp!
Also, the key doesn't get registered in the server:
root@mudskipper:~# postmap -v -q drebs@cdev.bitmask.net tcp:localhost:2424 postmap: name_mask: all postmap: inet_addr_local: configured 2 IPv4 addresses postmap: inet_addr_local: configured 2 IPv6 addresses postmap: dict_open: tcp:localhost:2424 postmap: dict_tcp_lookup: key drebs@cdev.bitmask.net postmap: trying... [127.0.0.1] postmap: dict_tcp_lookup: send: get drebs@cdev.bitmask.net postmap: dict_tcp_lookup: recv: 500 NOT%20FOUND%20SRY postmap: dict_tcp_lookup: not found: 500 NOT%20FOUND%20SRY root@mudskipper:~# postmap -v -q drebs@cdev.bitmask.net tcp:localhost:2244 postmap: name_mask: all postmap: inet_addr_local: configured 2 IPv4 addresses postmap: inet_addr_local: configured 2 IPv6 addresses postmap: dict_open: tcp:localhost:2244 postmap: dict_tcp_lookup: key drebs@cdev.bitmask.net postmap: trying... [127.0.0.1] postmap: dict_tcp_lookup: send: get drebs@cdev.bitmask.net postmap: dict_tcp_lookup: recv: 400 4.7.13%20NO%20PUBKEY%20FOUND postmap: dict_tcp_lookup: soft error: 400 4.7.13%20NO%20PUBKEY%20FOUND postmap: fatal: table tcp:localhost:2244: query error: Operation now in progress
(from redmine: created on 2016-09-12, closed on 2016-09-26)