soledad cannot sync big chunks
While researching other issues related to soledad, I noticed that one of my users cannot finish the initial soledad sync.
Maybe it's due to bad network connectivity from here, but I got constant timeouts while trying to sync.
2013-09-27 13:25:35,062 - leap.bitmask.services.soledad.soledadbootstrapper - DEBUG - current retries: 0, max retries: 10 2013-09-27 13:25:35,066 - leap.bitmask.services.soledad.soledadbootstrapper - DEBUG - Using soledad server url: https://clam.dev.bitmask.net:2323/user-f74ccf0aa010f34d44c22fe034fdfd0a 2013-09-27 13:25:35,067 - leap.bitmask.config.providerconfig - DEBUG - Going to verify SSL against /home/kali/.config/leap/providers/dev.bitmask.net/keys/ca/cacert.pem 2013-09-27 13:25:35,068 - leap.bitmask.services.soledad.soledadbootstrapper - DEBUG - local_db:/home/kali/.config/leap/soledad/f74ccf0aa010f34d44c22fe034fdfd0a.db 2013-09-27 13:25:35,071 - leap.bitmask.services.soledad.soledadbootstrapper - DEBUG - secrets_path:/home/kali/.config/leap/soledad/f74ccf0aa010f34d44c22fe034fdfd0a.secret 2013-09-27 13:25:35,072 - leap.bitmask.services.soledad.soledadbootstrapper - DEBUG - token: iucY39p_0fU9M2jcaJkE-vWrLcv46_CWaHah0UFkyh4 2013-09-27 13:26:25,481 - leap.bitmask.services.soledad.soledadbootstrapper - ERROR - Unhandled error while syncingsoledad: SSLError('The read operation timed out',) Traceback (most recent call last): File "/home/kali/leap/leap_client/src/leap/bitmask/services/soledad/soledadbootstrapper.py", line 186, in load_and_sync_soledad self._soledad.sync() File "/home/kali/leap/soledad/client/src/leap/soledad/client/__init__.py", line 941, in sync creds=self._creds, autocreate=True) File "/home/kali/leap/soledad/client/src/leap/soledad/client/sqlcipher.py", line 336, in sync crypto=self._crypto)).sync(autocreate=autocreate) File "/home/kali/Virtualenvs/leap-bitmask/local/lib/python2.7/site-packages/u1db-13.08-py2.7.egg/u1db/sync.py", line 147, in sync self._insert_doc_from_target, ensure_callback=ensure_callback) File "/home/kali/leap/soledad/client/src/leap/soledad/client/target.py", line 449, in sync_exchange data, _ = self._response() File "/home/kali/Virtualenvs/leap-bitmask/local/lib/python2.7/site-packages/u1db-13.08-py2.7.egg/u1db/remote/http_client.py", line 146, in _response body = resp.read() File "/usr/lib/python2.7/httplib.py", line 543, in read return self._read_chunked(amt) File "/usr/lib/python2.7/httplib.py", line 601, in _read_chunked value.append(self._safe_read(chunk_left)) File "/usr/lib/python2.7/httplib.py", line 658, in _safe_read chunk = self.fp.read(min(amt, MAXAMOUNT)) File "/usr/lib/python2.7/socket.py", line 380, in read data = self._sock.recv(left) File "/usr/lib/python2.7/ssl.py", line 305, in recv return self.read(buflen) File "/usr/lib/python2.7/ssl.py", line 224, in read return self._sslobj.read(len) SSLError: The read operation timed out 2013-09-27 13:26:25,487 - leap - DEBUG - 2013-09-27 13:26:25-0400 [-] Unhandled error in Deferred: 2013-09-27 13:26:25,491 - leap - DEBUG - 2013-09-27 13:26:25-0400 [-] Unhandled Error 2013-09-27 13:26:25,496 - leap - DEBUG - Traceback (most recent call last): 2013-09-27 13:26:25,498 - leap - DEBUG - File "/usr/lib/python2.7/threading.py", line 781, in __bootstrap 2013-09-27 13:26:25,501 - leap - DEBUG - self.__bootstrap_inner() 2013-09-27 13:26:25,506 - leap - DEBUG - File "/usr/lib/python2.7/threading.py", line 808, in __bootstrap_inner 2013-09-27 13:26:25,510 - leap - DEBUG - self.run() 2013-09-27 13:26:25,513 - leap - DEBUG - File "/usr/lib/python2.7/threading.py", line 761, in run 2013-09-27 13:26:25,513 - leap - DEBUG - self.__target(*self.__args, **self.__kwargs) 2013-09-27 13:26:25,514 - leap - DEBUG - --- --- 2013-09-27 13:26:25,521 - leap - DEBUG - File "/home/kali/Virtualenvs/leap-bitmask/local/lib/python2.7/site-packages/twisted/python/threadpool.py", line 191, in _worker 2013-09-27 13:26:25,521 - leap - DEBUG - result = context.call(ctx, function, *args, **kwargs) 2013-09-27 13:26:25,525 - leap - DEBUG - File "/home/kali/Virtualenvs/leap-bitmask/local/lib/python2.7/site-packages/twisted/python/context.py", line 118, in callWithContext 2013-09-27 13:26:25,526 - leap - DEBUG - return self.currentContext().callWithContext(ctx, func, *args, **kw) 2013-09-27 13:26:25,527 - leap - DEBUG - File "/home/kali/Virtualenvs/leap-bitmask/local/lib/python2.7/site-packages/twisted/python/context.py", line 81, in callWithContext 2013-09-27 13:26:25,528 - leap - DEBUG - return func(*args,**kw) 2013-09-27 13:26:25,535 - leap - DEBUG - File "/home/kali/leap/leap_client/src/leap/bitmask/services/soledad/soledadbootstrapper.py", line 191, in load_and_sync_soledad 2013-09-27 13:26:25,537 - leap - DEBUG - raise Exception("Cannot sync soledad") 2013-09-27 13:26:25,541 - leap - DEBUG - exceptions.Exception: Cannot sync soledad ^C2013-09-27 13:27:38,233 - leap - DEBUG - SIGINT catched. shutting down...
soledad logs
bad sync: (several retries, no luck) user: testmail (from long time ago, wiped out local db/secrets) 2013-09-27 19:27:49+0000 [-] 190.104.11.253 - - [27/Sep/2013:19:27:49 +0000] "GET /shared HTTP/1.1" 200 4 "-" "-" 2013-09-27 19:27:50+0000 [-] 190.104.11.253 - - [27/Sep/2013:19:27:50 +0000] "GET /shared/doc/ff68035b366d329e4963458bd29cfb1d18dd8ad742ec90b8dd0abf869abec5dc?include_deleted=false HTTP/1.1" 200 1679 "-" "-" 2013-09-27 19:27:52+0000 [-] 190.104.11.253 - - [27/Sep/2013:19:27:52 +0000] "GET /shared HTTP/1.1" 200 4 "-" "-" 2013-09-27 19:27:54+0000 [-] 190.104.11.253 - - [27/Sep/2013:19:27:54 +0000] "PUT /shared/doc/ff68035b366d329e4963458bd29cfb1d18dd8ad742ec90b8dd0abf869abec5dc?old_rev=320c9c281d354241999c48a0ca627f5c%3A126 HTTP/1.1" 200 49 "-" "-" 2013-09-27 19:27:59+0000 [-] 190.104.11.253 - - [27/Sep/2013:19:27:59 +0000] "GET /user-f74ccf0aa010f34d44c22fe034fdfd0a/sync-from/73ea4b10ec7749b9bc1e939c8c5de786 HTTP/1.1" 200 283 "-" "-" 2013-09-27 19:28:03+0000 [-] 190.104.11.253 - - [27/Sep/2013:19:28:03 +0000] "POST /user-f74ccf0aa010f34d44c22fe034fdfd0a/sync-from/73ea4b10ec7749b9bc1e939c8c5de786 HTTP/1.1" 200 444379 "-" "-" 2013-09-27 19:28:17+0000 [-] 190.104.11.253 - - [27/Sep/2013:19:28:17 +0000] "GET /user-f74ccf0aa010f34d44c22fe034fdfd0a/sync-from/73ea4b10ec7749b9bc1e939c8c5de786 HTTP/1.1" 200 283 "-" "-" 2013-09-27 19:28:28+0000 [-] 190.104.11.253 - - [27/Sep/2013:19:28:28 +0000] "GET /user-f74ccf0aa010f34d44c22fe034fdfd0a/sync-from/73ea4b10ec7749b9bc1e939c8c5de786 HTTP/1.1" 200 283 "-" "-" 2013-09-27 19:28:31+0000 [-] 190.104.11.253 - - [27/Sep/2013:19:28:31 +0000] "POST /user-f74ccf0aa010f34d44c22fe034fdfd0a/sync-from/73ea4b10ec7749b9bc1e939c8c5de786 HTTP/1.1" 200 444379 "-" "-" 2013-09-27 19:28:59+0000 [-] 190.104.11.253 - - [27/Sep/2013:19:28:59 +0000] "GET /user-f74ccf0aa010f34d44c22fe034fdfd0a/sync-from/73ea4b10ec7749b9bc1e939c8c5de786 HTTP/1.1" 200 283 "-" "-" 2013-09-27 19:29:10+0000 [-] 190.104.11.253 - - [27/Sep/2013:19:29:10 +0000] "GET /user-f74ccf0aa010f34d44c22fe034fdfd0a/sync-from/73ea4b10ec7749b9bc1e939c8c5de786 HTTP/1.1" 200 283 "-" "-" 2013-09-27 19:29:13+0000 [-] 190.104.11.253 - - [27/Sep/2013:19:29:13 +0000] "POST /user-f74ccf0aa010f34d44c22fe034fdfd0a/sync-from/73ea4b10ec7749b9bc1e939c8c5de786 HTTP/1.1" 200 444379 "-" "-" 2013-09-27 19:29:45+0000 [-] 190.104.11.253 - - [27/Sep/2013:19:29:45 +0000] "GET /user-f74ccf0aa010f34d44c22fe034fdfd0a/sync-from/73ea4b10ec7749b9bc1e939c8c5de786 HTTP/1.1" 200 283 "-" "-" 2013-09-27 19:29:48+0000 [-] 190.104.11.253 - - [27/Sep/2013:19:29:48 +0000] "POST /user-f74ccf0aa010f34d44c22fe034fdfd0a/sync-from/73ea4b10ec7749b9bc1e939c8c5de786 HTTP/1.1" 200 444379 "-" "-" 2013-09-27 19:29:50+0000 [-] 186.203.201.83 - - [27/Sep/2013:19:29:50 +0000] "GET /user-f01bc1c70de7d7d80bc1ad77d987f17e/sync-from/47c0a067a415475b9a6def9c6c39d548 HTTP/1.1" 200 318 "-" "-" 2013-09-27 19:29:59+0000 [-] 190.104.11.253 - - [27/Sep/2013:19:29:59 +0000] "GET /user-f74ccf0aa010f34d44c22fe034fdfd0a/sync-from/73ea4b10ec7749b9bc1e939c8c5de786 HTTP/1.1" 200 283 "-" "-" 2013-09-27 19:30:03+0000 [-] 190.104.11.253 - - [27/Sep/2013:19:30:03 +0000] "POST /user-f74ccf0aa010f34d44c22fe034fdfd0a/sync-from/73ea4b10ec7749b9bc1e939c8c5de786 HTTP/1.1" 200 444379 "-" "-" 2013-09-27 19:30:23+0000 [-] 190.104.11.253 - - [27/Sep/2013:19:30:23 +0000] "GET /user-f74ccf0aa010f34d44c22fe034fdfd0a/sync-from/73ea4b10ec7749b9bc1e939c8c5de786 HTTP/1.1" 200 283 "-" "-" 2013-09-27 19:30:29+0000 [-] 190.104.11.253 - - [27/Sep/2013:19:30:29 +0000] "POST /user-f74ccf0aa010f34d44c22fe034fdfd0a/sync-from/73ea4b10ec7749b9bc1e939c8c5de786 HTTP/1.1" 200 444379 "-" "-" 2013-09-27 19:30:53+0000 [-] 190.104.11.253 - - [27/Sep/2013:19:30:53 +0000] "GET /user-f74ccf0aa010f34d44c22fe034fdfd0a/sync-from/73ea4b10ec7749b9bc1e939c8c5de786 HTTP/1.1" 200 283 "-" "-" 2013-09-27 19:30:57+0000 [-] 190.104.11.253 - - [27/Sep/2013:19:30:57 +0000] "POST /user-f74ccf0aa010f34d44c22fe034fdfd0a/sync-from/73ea4b10ec7749b9bc1e939c8c5de786 HTTP/1.1" 200 444379 "-" "-" 2013-09-27 19:31:12+0000 [-] 190.104.11.253 - - [27/Sep/2013:19:31:12 +0000] "GET /user-f74ccf0aa010f34d44c22fe034fdfd0a/sync-from/73ea4b10ec7749b9bc1e939c8c5de786 HTTP/1.1" 200 283 "-" "-" 2013-09-27 19:31:16+0000 [-] 190.104.11.253 - - [27/Sep/2013:19:31:16 +0000] "POST /user-f74ccf0aa010f34d44c22fe034fdfd0a/sync-from/73ea4b10ec7749b9bc1e939c8c5de786 HTTP/1.1" 200 444379 "-" "-" 2013-09-27 19:32:28+0000 [-] 190.104.11.253 - - [27/Sep/2013:19:32:27 +0000] "GET /user-f74ccf0aa010f34d44c22fe034fdfd0a/sync-from/73ea4b10ec7749b9bc1e939c8c5de786 HTTP/1.1" 200 283 "-" "-" 2013-09-27 19:32:31+0000 [-] 190.104.11.253 - - [27/Sep/2013:19:32:31 +0000] "POST /user-f74ccf0aa010f34d44c22fe034fdfd0a/sync-from/73ea4b10ec7749b9bc1e939c8c5de786 HTTP/1.1" 200 444379 "-" "-" 2013-09-27 19:32:57+0000 [-] 190.104.11.253 - - [27/Sep/2013:19:32:57 +0000] "GET /user-f74ccf0aa010f34d44c22fe034fdfd0a/sync-from/73ea4b10ec7749b9bc1e939c8c5de786 HTTP/1.1" 200 283 "-" "-" 2013-09-27 19:33:10+0000 [-] 190.104.11.253 - - [27/Sep/2013:19:33:09 +0000] "GET /user-f74ccf0aa010f34d44c22fe034fdfd0a/sync-from/73ea4b10ec7749b9bc1e939c8c5de786 HTTP/1.1" 200 283 "-" "-" 2013-09-27 19:33:19+0000 [-] 190.104.11.253 - - [27/Sep/2013:19:33:19 +0000] "POST /user-f74ccf0aa010f34d44c22fe034fdfd0a/sync-from/73ea4b10ec7749b9bc1e939c8c5de786 HTTP/1.1" 200 444379 "-" "-" 2013-09-27 19:33:48+0000 [-] 190.104.11.253 - - [27/Sep/2013:19:33:48 +0000] "GET /user-f74ccf0aa010f34d44c22fe034fdfd0a/sync-from/73ea4b10ec7749b9bc1e939c8c5de786 HTTP/1.1" 200 283 "-" "-" 2013-09-27 19:33:56+0000 [-] 190.104.11.253 - - [27/Sep/2013:19:33:56 +0000] "POST /user-f74ccf0aa010f34d44c22fe034fdfd0a/sync-from/73ea4b10ec7749b9bc1e939c8c5de786 HTTP/1.1" 200 444379 "-" "-" good sync: user: testmail003 (just created) 2013-09-27 19:54:42+0000 [-] 190.104.11.253 - - [27/Sep/2013:19:54:42 +0000] "GET /user-f01bc1c70de7d7d80bc1ad77d987be68/sync-from/af6568fa71f24ca6b3135afc64b112c8 HTTP/1.1" 404 38 "-" "-" 2013-09-27 19:54:50+0000 [-] 186.203.201.83 - - [27/Sep/2013:19:54:50 +0000] "GET /user-f01bc1c70de7d7d80bc1ad77d987f17e/sync-from/47c0a067a415475b9a6def9c6c39d548 HTTP/1.1" 200 318 "-" "-" 2013-09-27 19:55:04+0000 [-] 190.104.11.253 - - [27/Sep/2013:19:55:03 +0000] "POST /user-f01bc1c70de7d7d80bc1ad77d987be68/sync-from/af6568fa71f24ca6b3135afc64b112c8 HTTP/1.1" 200 140 "-" "-" 2013-09-27 19:55:12+0000 [-] 190.104.11.253 - - [27/Sep/2013:19:55:11 +0000] "GET /user-f01bc1c70de7d7d80bc1ad77d987be68/sync-from/af6568fa71f24ca6b3135afc64b112c8 HTTP/1.1" 200 316 "-" "-" 2013-09-27 19:55:22+0000 [-] 190.104.11.253 - - [27/Sep/2013:19:55:21 +0000] "GET /user-f01bc1c70de7d7d80bc1ad77d987be68/sync-from/af6568fa71f24ca6b3135afc64b112c8 HTTP/1.1" 200 316 "-" "-" 2013-09-27 19:55:32+0000 [-] 190.104.11.253 - - [27/Sep/2013:19:55:31 +0000] "GET /user-f01bc1c70de7d7d80bc1ad77d987be68/sync-from/af6568fa71f24ca6b3135afc64b112c8 HTTP/1.1" 200 316 "-" "-"
(from redmine: created on 2013-09-27, closed on 2016-07-28)
- Relations:
- relates #3967 (closed)
- relates #4615
- relates #3966
- child #5752 (closed)
- parent #5849 (closed)