From 1c8b39b808a5d5b56f5463d29ad1a7e901bf84d5 Mon Sep 17 00:00:00 2001 From: Victor Shyba Date: Tue, 2 Aug 2016 00:07:13 -0300 Subject: [test] avoid race condition on test_processing_order test_processing_order aims to check that unordered docs wont be processed, but if we let the pool start and advance Twisted LoopingCall clock right before calling the processing method manually, the process method will run concurrently and cause a race condition issue. --- client/src/leap/soledad/client/encdecpool.py | 5 ++++- 1 file changed, 4 insertions(+), 1 deletion(-) (limited to 'client/src/leap') diff --git a/client/src/leap/soledad/client/encdecpool.py b/client/src/leap/soledad/client/encdecpool.py index a6d49b21..2cf5da6e 100644 --- a/client/src/leap/soledad/client/encdecpool.py +++ b/client/src/leap/soledad/client/encdecpool.py @@ -344,6 +344,9 @@ class SyncDecrypterPool(SyncEncryptDecryptPool): self._loop = LoopingCall(self._decrypt_and_recurse) + def _start_pool(self, period): + self._loop.start(period) + def start(self, docs_to_process): """ Set the number of documents we expect to process. @@ -360,7 +363,7 @@ class SyncDecrypterPool(SyncEncryptDecryptPool): self._docs_to_process = docs_to_process self._deferred = defer.Deferred() d = self._init_db() - d.addCallback(lambda _: self._loop.start(self.DECRYPT_LOOP_PERIOD)) + d.addCallback(lambda _: self._start_pool(self.DECRYPT_LOOP_PERIOD)) return d def stop(self): -- cgit v1.2.3 From 062d781b734db60d0ae317eaf5b86c7d75abacd9 Mon Sep 17 00:00:00 2001 From: Victor Shyba Date: Sat, 20 Aug 2016 00:44:02 -0300 Subject: [bug] limit pool comnsumption to 900 docs This was discovered during load tests: Trying to process more than 999 docs triggers an error on SQLite due a select query not supporting 999 values to query. --- client/src/leap/soledad/client/encdecpool.py | 2 ++ 1 file changed, 2 insertions(+) (limited to 'client/src/leap') diff --git a/client/src/leap/soledad/client/encdecpool.py b/client/src/leap/soledad/client/encdecpool.py index 2cf5da6e..7be6030e 100644 --- a/client/src/leap/soledad/client/encdecpool.py +++ b/client/src/leap/soledad/client/encdecpool.py @@ -556,6 +556,8 @@ class SyncDecrypterPool(SyncEncryptDecryptPool): while next_index in self._decrypted_docs_indexes: sequence.append(str(next_index)) next_index += 1 + if len(sequence) > 900: + break # SQLITE_LIMIT_VARIABLE_NUMBER # Then fetch all the ones ready for insertion. if sequence: insertable_docs = yield self._get_docs(encrypted=False, -- cgit v1.2.3 From eaf8907696a7b5ae0b1411f0770f59c0ed5f9fc4 Mon Sep 17 00:00:00 2001 From: Victor Shyba Date: Tue, 23 Aug 2016 15:48:55 -0300 Subject: [doc] improve SQLITE_MAX_VARIABLE_NUMBER comments --- client/src/leap/soledad/client/encdecpool.py | 6 +++++- 1 file changed, 5 insertions(+), 1 deletion(-) (limited to 'client/src/leap') diff --git a/client/src/leap/soledad/client/encdecpool.py b/client/src/leap/soledad/client/encdecpool.py index 7be6030e..74a40931 100644 --- a/client/src/leap/soledad/client/encdecpool.py +++ b/client/src/leap/soledad/client/encdecpool.py @@ -557,7 +557,11 @@ class SyncDecrypterPool(SyncEncryptDecryptPool): sequence.append(str(next_index)) next_index += 1 if len(sequence) > 900: - break # SQLITE_LIMIT_VARIABLE_NUMBER + # 999 is the default value of SQLITE_MAX_VARIABLE_NUMBER + # if we try to query more, SQLite will refuse + # we need to find a way to improve this + # being researched in #7669 + break # Then fetch all the ones ready for insertion. if sequence: insertable_docs = yield self._get_docs(encrypted=False, -- cgit v1.2.3 From 6b283761de3a845d09de20fcc2b6a4a63130e45f Mon Sep 17 00:00:00 2001 From: Kali Kaneko Date: Thu, 1 Sep 2016 00:55:26 -0400 Subject: [bug] fail gracefully if dbsyncer has not been initialized this is needed for some mail tests. --- client/src/leap/soledad/client/api.py | 2 ++ 1 file changed, 2 insertions(+) (limited to 'client/src/leap') diff --git a/client/src/leap/soledad/client/api.py b/client/src/leap/soledad/client/api.py index 1bfbed8a..fbf605a9 100644 --- a/client/src/leap/soledad/client/api.py +++ b/client/src/leap/soledad/client/api.py @@ -736,6 +736,8 @@ class Soledad(object): :rtype: twisted.internet.defer.Deferred """ sync_url = urlparse.urljoin(self._server_url, 'user-%s' % self.uuid) + if not self._dbsyncer: + return d = self._dbsyncer.sync( sync_url, creds=self._creds, -- cgit v1.2.3 From b7340a962bfeae9af28c4b514d0eb077f41dd832 Mon Sep 17 00:00:00 2001 From: drebs Date: Thu, 22 Sep 2016 14:44:46 -0300 Subject: [feat] centralize logging and use twisted.logger by default --- client/src/leap/soledad/client/adbapi.py | 19 ++++++------------- client/src/leap/soledad/client/api.py | 4 ++-- client/src/leap/soledad/client/crypto.py | 6 +++--- client/src/leap/soledad/client/encdecpool.py | 7 +++---- .../src/leap/soledad/client/http_target/__init__.py | 4 ++-- client/src/leap/soledad/client/http_target/api.py | 1 - client/src/leap/soledad/client/http_target/fetch.py | 4 ++-- client/src/leap/soledad/client/http_target/send.py | 5 ++--- client/src/leap/soledad/client/pragmas.py | 4 ++-- client/src/leap/soledad/client/secrets.py | 8 ++++---- client/src/leap/soledad/client/sqlcipher.py | 8 ++++---- client/src/leap/soledad/client/sync.py | 5 ++--- 12 files changed, 32 insertions(+), 43 deletions(-) (limited to 'client/src/leap') diff --git a/client/src/leap/soledad/client/adbapi.py b/client/src/leap/soledad/client/adbapi.py index ef0f9066..ce9bec05 100644 --- a/client/src/leap/soledad/client/adbapi.py +++ b/client/src/leap/soledad/client/adbapi.py @@ -19,31 +19,25 @@ An asyncrhonous interface to soledad using sqlcipher backend. It uses twisted.enterprise.adbapi. """ import re -import os import sys -import logging from functools import partial from twisted.enterprise import adbapi from twisted.internet.defer import DeferredSemaphore -from twisted.python import log from zope.proxy import ProxyBase, setProxiedObject from pysqlcipher import dbapi2 +from leap.soledad.common.log import getLogger from leap.soledad.common.errors import DatabaseAccessError from leap.soledad.client import sqlcipher as soledad_sqlcipher from leap.soledad.client.pragmas import set_init_pragmas -logger = logging.getLogger(name=__name__) +logger = getLogger(__name__) -DEBUG_SQL = os.environ.get("LEAP_DEBUG_SQL") -if DEBUG_SQL: - log.startLogging(sys.stdout) - """ How long the SQLCipher connection should wait for the lock to go away until raising an exception. @@ -221,13 +215,12 @@ class U1DBConnectionPool(adbapi.ConnectionPool): def _errback(failure): failure.trap(dbapi2.OperationalError) if failure.getErrorMessage() == "database is locked": - logger.warning("Database operation timed out.") + logger.warn("database operation timed out") should_retry = semaphore.acquire() if should_retry: - logger.warning( - "Database operation timed out while waiting for " - "lock, trying again...") + logger.warn("trying again...") return _run_interaction() + logger.warn("giving up!") return failure d = _run_interaction() @@ -286,7 +279,7 @@ class U1DBConnectionPool(adbapi.ConnectionPool): try: conn.rollback() except: - log.err(None, "Rollback failed") + logger.error(None, "Rollback failed") raise excType, excValue, excTraceback def finalClose(self): diff --git a/client/src/leap/soledad/client/api.py b/client/src/leap/soledad/client/api.py index fbf605a9..f620f1bc 100644 --- a/client/src/leap/soledad/client/api.py +++ b/client/src/leap/soledad/client/api.py @@ -28,7 +28,6 @@ remote storage in the server side. import binascii import errno import httplib -import logging import os import socket import ssl @@ -49,6 +48,7 @@ from leap.common.plugins import collect_plugins from leap.soledad.common import SHARED_DB_NAME from leap.soledad.common import soledad_assert from leap.soledad.common import soledad_assert_type +from leap.soledad.common.log import getLogger from leap.soledad.common.l2db.remote import http_client from leap.soledad.common.l2db.remote.ssl_match_hostname import match_hostname from leap.soledad.common.errors import DatabaseAccessError @@ -62,7 +62,7 @@ from leap.soledad.client.shared_db import SoledadSharedDatabase from leap.soledad.client import sqlcipher from leap.soledad.client import encdecpool -logger = logging.getLogger(name=__name__) +logger = getLogger(__name__) # we may want to collect statistics from the sync process diff --git a/client/src/leap/soledad/client/crypto.py b/client/src/leap/soledad/client/crypto.py index f7d92372..9f5fe28e 100644 --- a/client/src/leap/soledad/client/crypto.py +++ b/client/src/leap/soledad/client/crypto.py @@ -22,7 +22,6 @@ import binascii import hmac import hashlib import json -import logging from cryptography.hazmat.primitives.ciphers import Cipher, algorithms, modes from cryptography.hazmat.backends.multibackend import MultiBackend @@ -32,9 +31,10 @@ from cryptography.hazmat.backends.openssl.backend \ from leap.soledad.common import soledad_assert from leap.soledad.common import soledad_assert_type from leap.soledad.common import crypto +from leap.soledad.common.log import getLogger -logger = logging.getLogger(__name__) +logger = getLogger(__name__) MAC_KEY_LENGTH = 64 @@ -356,7 +356,7 @@ def _verify_doc_mac(doc_id, doc_rev, ciphertext, enc_scheme, enc_method, calculated_mac_hash = hashlib.sha256(calculated_mac).digest() if doc_mac_hash != calculated_mac_hash: - logger.warning("Wrong MAC while decrypting doc...") + logger.warn("Wrong MAC while decrypting doc...") raise crypto.WrongMacError("Could not authenticate document's " "contents.") diff --git a/client/src/leap/soledad/client/encdecpool.py b/client/src/leap/soledad/client/encdecpool.py index 74a40931..c1a7f651 100644 --- a/client/src/leap/soledad/client/encdecpool.py +++ b/client/src/leap/soledad/client/encdecpool.py @@ -23,22 +23,21 @@ during synchronization. import json -import logging from uuid import uuid4 from twisted.internet.task import LoopingCall from twisted.internet import threads from twisted.internet import defer -from twisted.python import log from leap.soledad.common.document import SoledadDocument from leap.soledad.common import soledad_assert +from leap.soledad.common.log import getLogger from leap.soledad.client.crypto import encrypt_docstr from leap.soledad.client.crypto import decrypt_doc_dict -logger = logging.getLogger(__name__) +logger = getLogger(__name__) # @@ -393,7 +392,7 @@ class SyncDecrypterPool(SyncEncryptDecryptPool): return d def _errback(self, failure): - log.err(failure) + logger.error(failure) self._deferred.errback(failure) self._processed_docs = 0 self._last_inserted_idx = 0 diff --git a/client/src/leap/soledad/client/http_target/__init__.py b/client/src/leap/soledad/client/http_target/__init__.py index b7e54aa4..62e8bcf0 100644 --- a/client/src/leap/soledad/client/http_target/__init__.py +++ b/client/src/leap/soledad/client/http_target/__init__.py @@ -23,15 +23,15 @@ after receiving. import os -import logging +from leap.soledad.common.log import getLogger from leap.common.http import HTTPClient from leap.soledad.client.http_target.send import HTTPDocSender from leap.soledad.client.http_target.api import SyncTargetAPI from leap.soledad.client.http_target.fetch import HTTPDocFetcher -logger = logging.getLogger(__name__) +logger = getLogger(__name__) # we may want to collect statistics from the sync process diff --git a/client/src/leap/soledad/client/http_target/api.py b/client/src/leap/soledad/client/http_target/api.py index f8de9a15..3c8e3764 100644 --- a/client/src/leap/soledad/client/http_target/api.py +++ b/client/src/leap/soledad/client/http_target/api.py @@ -15,7 +15,6 @@ # You should have received a copy of the GNU General Public License # along with this program. If not, see . import os -import time import json import base64 diff --git a/client/src/leap/soledad/client/http_target/fetch.py b/client/src/leap/soledad/client/http_target/fetch.py index a3f70b02..184c5883 100644 --- a/client/src/leap/soledad/client/http_target/fetch.py +++ b/client/src/leap/soledad/client/http_target/fetch.py @@ -14,7 +14,6 @@ # # You should have received a copy of the GNU General Public License # along with this program. If not, see . -import logging import json from twisted.internet import defer @@ -24,11 +23,12 @@ from leap.soledad.client.events import emit_async from leap.soledad.client.crypto import is_symmetrically_encrypted from leap.soledad.client.encdecpool import SyncDecrypterPool from leap.soledad.client.http_target.support import RequestBody +from leap.soledad.common.log import getLogger from leap.soledad.common.document import SoledadDocument from leap.soledad.common.l2db import errors from leap.soledad.common.l2db.remote import utils -logger = logging.getLogger(__name__) +logger = getLogger(__name__) class HTTPDocFetcher(object): diff --git a/client/src/leap/soledad/client/http_target/send.py b/client/src/leap/soledad/client/http_target/send.py index 13218acf..c7bd057e 100644 --- a/client/src/leap/soledad/client/http_target/send.py +++ b/client/src/leap/soledad/client/http_target/send.py @@ -15,15 +15,15 @@ # You should have received a copy of the GNU General Public License # along with this program. If not, see . import json -import logging from twisted.internet import defer +from leap.soledad.common.log import getLogger from leap.soledad.client.events import emit_async from leap.soledad.client.events import SOLEDAD_SYNC_SEND_STATUS from leap.soledad.client.http_target.support import RequestBody -logger = logging.getLogger(__name__) +logger = getLogger(__name__) class HTTPDocSender(object): @@ -82,7 +82,6 @@ class HTTPDocSender(object): if self._defer_encryption: self._delete_sent(sent) - user_data = {'uuid': self.uuid, 'userid': self.userid} _emit_send_status(self.uuid, body.consumed, total) defer.returnValue(result) diff --git a/client/src/leap/soledad/client/pragmas.py b/client/src/leap/soledad/client/pragmas.py index 55397d10..3c3e7aab 100644 --- a/client/src/leap/soledad/client/pragmas.py +++ b/client/src/leap/soledad/client/pragmas.py @@ -17,15 +17,15 @@ """ Different pragmas used in the initialization of the SQLCipher database. """ -import logging import string import threading import os from leap.soledad.common import soledad_assert +from leap.soledad.common.log import getLogger -logger = logging.getLogger(__name__) +logger = getLogger(__name__) _db_init_lock = threading.Lock() diff --git a/client/src/leap/soledad/client/secrets.py b/client/src/leap/soledad/client/secrets.py index 3547a711..b7bcdd0a 100644 --- a/client/src/leap/soledad/client/secrets.py +++ b/client/src/leap/soledad/client/secrets.py @@ -23,7 +23,6 @@ Soledad secrets handling. import os import scrypt -import logging import binascii import errno import json @@ -33,11 +32,12 @@ from hashlib import sha256 from leap.soledad.common import soledad_assert from leap.soledad.common import soledad_assert_type from leap.soledad.common import document +from leap.soledad.common.log import getLogger from leap.soledad.client import events from leap.soledad.client.crypto import encrypt_sym, decrypt_sym -logger = logging.getLogger(name=__name__) +logger = getLogger(__name__) # @@ -461,7 +461,7 @@ class SoledadSecrets(object): events.emit_async(events.SOLEDAD_DOWNLOADING_KEYS, user_data) db = self._shared_db if not db: - logger.warning('No shared db found') + logger.warn('no shared db found') return doc = db.get_doc(self._shared_db_doc_id()) user_data = {'userid': self._userid, 'uuid': self._uuid} @@ -492,7 +492,7 @@ class SoledadSecrets(object): events.emit_async(events.SOLEDAD_UPLOADING_KEYS, user_data) db = self._shared_db if not db: - logger.warning('No shared db found') + logger.warn('no shared db found') return db.put_doc(doc) events.emit_async(events.SOLEDAD_DONE_UPLOADING_KEYS, user_data) diff --git a/client/src/leap/soledad/client/sqlcipher.py b/client/src/leap/soledad/client/sqlcipher.py index 166c0783..14d6f5ae 100644 --- a/client/src/leap/soledad/client/sqlcipher.py +++ b/client/src/leap/soledad/client/sqlcipher.py @@ -41,7 +41,6 @@ So, as the statements above were introduced for backwards compatibility with SQLCipher 1.1 databases, we do not implement them as all SQLCipher databases handled by Soledad should be created by SQLCipher >= 2.0. """ -import logging import os import json @@ -55,8 +54,9 @@ from twisted.internet import defer from twisted.enterprise import adbapi from leap.soledad.common.document import SoledadDocument -from leap.soledad.common import l2db +from leap.soledad.common.log import getLogger from leap.soledad.common.l2db import errors as u1db_errors +from leap.soledad.common.l2db import Document from leap.soledad.common.l2db.backends import sqlite_backend from leap.soledad.common.errors import DatabaseAccessError @@ -65,7 +65,7 @@ from leap.soledad.client.sync import SoledadSynchronizer from leap.soledad.client import pragmas -logger = logging.getLogger(__name__) +logger = getLogger(__name__) # Monkey-patch u1db.backends.sqlite_backend with pysqlcipher.dbapi2 @@ -595,7 +595,7 @@ class U1DBSQLiteBackend(sqlite_backend.SQLitePartialExpandDatabase): self._db_handle = conn self._real_replica_uid = None self._ensure_schema() - self._factory = l2db.Document + self._factory = Document class SoledadSQLCipherWrapper(SQLCipherDatabase): diff --git a/client/src/leap/soledad/client/sync.py b/client/src/leap/soledad/client/sync.py index 2656a150..335daaef 100644 --- a/client/src/leap/soledad/client/sync.py +++ b/client/src/leap/soledad/client/sync.py @@ -18,17 +18,16 @@ Soledad synchronization utilities. """ import os -import time -import logging from twisted.internet import defer +from leap.soledad.common.log import getLogger from leap.soledad.common.l2db import errors from leap.soledad.common.l2db.sync import Synchronizer from leap.soledad.common.errors import BackendNotReadyError -logger = logging.getLogger(__name__) +logger = getLogger(__name__) # we may want to collect statistics from the sync process -- cgit v1.2.3 From b1a7b538ab851c9e1aab3be5ba31411d658a4773 Mon Sep 17 00:00:00 2001 From: drebs Date: Thu, 22 Sep 2016 15:32:34 -0300 Subject: [style] standardize log messages --- client/src/leap/soledad/client/api.py | 6 ++--- client/src/leap/soledad/client/crypto.py | 4 +-- client/src/leap/soledad/client/encdecpool.py | 10 ++++---- client/src/leap/soledad/client/pragmas.py | 8 +++--- client/src/leap/soledad/client/secrets.py | 20 +++++++-------- client/src/leap/soledad/client/sync.py | 37 +++++++++++----------------- 6 files changed, 38 insertions(+), 47 deletions(-) (limited to 'client/src/leap') diff --git a/client/src/leap/soledad/client/api.py b/client/src/leap/soledad/client/api.py index f620f1bc..6870d5ba 100644 --- a/client/src/leap/soledad/client/api.py +++ b/client/src/leap/soledad/client/api.py @@ -337,7 +337,7 @@ class Soledad(object): """ Close underlying U1DB database. """ - logger.debug("Closing soledad") + logger.debug("closing soledad") self._dbpool.close() if getattr(self, '_dbsyncer', None): self._dbsyncer.close() @@ -763,7 +763,7 @@ class Soledad(object): def _sync_errback(failure): s = StringIO() failure.printDetailedTraceback(file=s) - msg = "Soledad exception when syncing!\n" + s.getvalue() + msg = "got exception when syncing!\n" + s.getvalue() logger.error(msg) return failure @@ -1005,7 +1005,7 @@ class Soledad(object): def create_path_if_not_exists(path): try: if not os.path.isdir(path): - logger.info('Creating directory: %s.' % path) + logger.info('creating directory: %s.' % path) os.makedirs(path) except OSError as exc: if exc.errno == errno.EEXIST and os.path.isdir(path): diff --git a/client/src/leap/soledad/client/crypto.py b/client/src/leap/soledad/client/crypto.py index 9f5fe28e..d81c883b 100644 --- a/client/src/leap/soledad/client/crypto.py +++ b/client/src/leap/soledad/client/crypto.py @@ -300,7 +300,7 @@ def encrypt_docstr(docstr, doc_id, doc_rev, key, secret): # convert binary data to hexadecimal representation so the JSON # serialization does not complain about what it tries to serialize. hex_ciphertext = binascii.b2a_hex(ciphertext) - logger.debug("Encrypting doc: %s" % doc_id) + logger.debug("encrypting doc: %s" % doc_id) return json.dumps({ crypto.ENC_JSON_KEY: hex_ciphertext, crypto.ENC_SCHEME_KEY: enc_scheme, @@ -356,7 +356,7 @@ def _verify_doc_mac(doc_id, doc_rev, ciphertext, enc_scheme, enc_method, calculated_mac_hash = hashlib.sha256(calculated_mac).digest() if doc_mac_hash != calculated_mac_hash: - logger.warn("Wrong MAC while decrypting doc...") + logger.warn("wrong MAC while decrypting doc...") raise crypto.WrongMacError("Could not authenticate document's " "contents.") diff --git a/client/src/leap/soledad/client/encdecpool.py b/client/src/leap/soledad/client/encdecpool.py index c1a7f651..056b012f 100644 --- a/client/src/leap/soledad/client/encdecpool.py +++ b/client/src/leap/soledad/client/encdecpool.py @@ -154,7 +154,7 @@ class SyncEncrypterPool(SyncEncryptDecryptPool): Start the encrypter pool. """ SyncEncryptDecryptPool.start(self) - logger.debug("Starting the encryption loop...") + logger.debug("starting the encryption loop...") def stop(self): """ @@ -229,10 +229,10 @@ class SyncEncrypterPool(SyncEncryptDecryptPool): % self.TABLE_NAME result = yield self._runQuery(query, (doc_id, doc_rev)) if result: - logger.debug("Found doc on sync db: %s" % doc_id) + logger.debug("found doc on sync db: %s" % doc_id) val = result.pop() defer.returnValue(val[0]) - logger.debug("Did not find doc on sync db: %s" % doc_id) + logger.debug("did not find doc on sync db: %s" % doc_id) defer.returnValue(None) def delete_encrypted_doc(self, doc_id, doc_rev): @@ -505,7 +505,7 @@ class SyncDecrypterPool(SyncEncryptDecryptPool): :rtype: twisted.internet.defer.Deferred """ doc_id, rev, content, gen, trans_id, idx = result - logger.debug("Sync decrypter pool: decrypted doc %s: %s %s %s" + logger.debug("sync decrypter pool: decrypted doc %s: %s %s %s" % (doc_id, rev, gen, trans_id)) return self.insert_received_doc( doc_id, rev, content, gen, trans_id, idx) @@ -610,7 +610,7 @@ class SyncDecrypterPool(SyncEncryptDecryptPool): :type trans_id: str """ # could pass source_replica in params for callback chain - logger.debug("Sync decrypter pool: inserting doc in local db: " + logger.debug("sync decrypter pool: inserting doc in local db: " "%s:%s %s" % (doc_id, doc_rev, gen)) # convert deleted documents to avoid error on document creation diff --git a/client/src/leap/soledad/client/pragmas.py b/client/src/leap/soledad/client/pragmas.py index 3c3e7aab..870ed63e 100644 --- a/client/src/leap/soledad/client/pragmas.py +++ b/client/src/leap/soledad/client/pragmas.py @@ -321,7 +321,7 @@ def set_synchronous_off(db_handle): """ Change the setting of the "synchronous" flag to OFF. """ - logger.debug("SQLCIPHER: SETTING SYNCHRONOUS OFF") + logger.debug("sqlcipher: setting synchronous off") db_handle.cursor().execute('PRAGMA synchronous=OFF') @@ -329,7 +329,7 @@ def set_synchronous_normal(db_handle): """ Change the setting of the "synchronous" flag to NORMAL. """ - logger.debug("SQLCIPHER: SETTING SYNCHRONOUS NORMAL") + logger.debug("sqlcipher: setting synchronous normal") db_handle.cursor().execute('PRAGMA synchronous=NORMAL') @@ -337,7 +337,7 @@ def set_mem_temp_store(db_handle): """ Use a in-memory store for temporary tables. """ - logger.debug("SQLCIPHER: SETTING TEMP_STORE MEMORY") + logger.debug("sqlcipher: setting temp_store memory") db_handle.cursor().execute('PRAGMA temp_store=MEMORY') @@ -362,7 +362,7 @@ def set_write_ahead_logging(db_handle): requirements of the application. The default strategy is to run a checkpoint once the WAL reaches 1000 pages" """ - logger.debug("SQLCIPHER: SETTING WRITE-AHEAD LOGGING") + logger.debug("sqlcipher: setting write-ahead logging") db_handle.cursor().execute('PRAGMA journal_mode=WAL') # The optimum value can still use a little bit of tuning, but we favor diff --git a/client/src/leap/soledad/client/secrets.py b/client/src/leap/soledad/client/secrets.py index b7bcdd0a..1eb6f31d 100644 --- a/client/src/leap/soledad/client/secrets.py +++ b/client/src/leap/soledad/client/secrets.py @@ -193,42 +193,42 @@ class SoledadSecrets(object): """ # STAGE 1 - verify if secrets exist locally try: - logger.info("Trying to load secrets from local storage...") + logger.info("trying to load secrets from local storage...") version = self._load_secrets_from_local_file() # eventually migrate local and remote stored documents from old # format version if version < self.RECOVERY_DOC_VERSION: self._store_secrets() self._upload_crypto_secrets() - logger.info("Found secrets in local storage.") + logger.info("found secrets in local storage") return except NoStorageSecret: - logger.info("Could not find secrets in local storage.") + logger.info("could not find secrets in local storage") # STAGE 2 - there are no secrets in local storage and this is the # first time we are running soledad with the specified # secrets_path. Try to fetch encrypted secrets from # server. try: - logger.info('Trying to fetch secrets from remote storage...') + logger.info('trying to fetch secrets from remote storage...') version = self._download_crypto_secrets() self._store_secrets() # eventually migrate remote stored document from old format # version if version < self.RECOVERY_DOC_VERSION: self._upload_crypto_secrets() - logger.info('Found secrets in remote storage.') + logger.info('found secrets in remote storage.') return except NoStorageSecret: - logger.info("Could not find secrets in remote storage.") + logger.info("could not find secrets in remote storage.") # STAGE 3 - there are no secrets in server also, so we want to # generate the secrets and store them in the remote # db. - logger.info("Generating secrets...") + logger.info("generating secrets...") self._gen_crypto_secrets() - logger.info("Uploading secrets...") + logger.info("uploading secrets...") self._upload_crypto_secrets() def _has_secret(self): @@ -298,7 +298,7 @@ class SoledadSecrets(object): """ Generate the crypto secrets. """ - logger.info('No cryptographic secrets found, creating new secrets...') + logger.info('no cryptographic secrets found, creating new secrets...') secret_id = self._gen_secret() self.set_secret_id(secret_id) @@ -445,7 +445,7 @@ class SoledadSecrets(object): encrypted_secret) secret_count += 1 except SecretsException as e: - logger.error("Failed to decrypt storage secret: %s" + logger.error("failed to decrypt storage secret: %s" % str(e)) return secret_count, active_secret diff --git a/client/src/leap/soledad/client/sync.py b/client/src/leap/soledad/client/sync.py index 335daaef..0c68d100 100644 --- a/client/src/leap/soledad/client/sync.py +++ b/client/src/leap/soledad/client/sync.py @@ -101,16 +101,12 @@ class SoledadSynchronizer(Synchronizer): target_gen, target_trans_id = 0, '' target_my_gen, target_my_trans_id = 0, '' - logger.debug( - "Soledad target sync info:\n" - " target replica uid: %s\n" - " target generation: %d\n" - " target trans id: %s\n" - " target my gen: %d\n" - " target my trans_id: %s\n" - " source replica_uid: %s\n" - % (self.target_replica_uid, target_gen, target_trans_id, - target_my_gen, target_my_trans_id, self.source._replica_uid)) + logger.debug("target replica uid: %s" % self.target_replica_uid) + logger.debug("target generation: %d" % target_gen) + logger.debug("target trans id: %s" % target_trans_id) + logger.debug("target my gen: %d" % target_my_gen) + logger.debug("target my trans_id: %s" % target_my_trans_id) + logger.debug("source replica_uid: %s" % self.source._replica_uid) # make sure we'll have access to target replica uid once it exists if self.target_replica_uid is None: @@ -133,8 +129,7 @@ class SoledadSynchronizer(Synchronizer): # what's changed since that generation and this current gen my_gen, _, changes = self.source.whats_changed(target_my_gen) - logger.debug("Soledad sync: there are %d documents to send." - % len(changes)) + logger.debug("there are %d documents to send" % len(changes)) # get source last-seen database generation for the target if self.target_replica_uid is None: @@ -143,11 +138,10 @@ class SoledadSynchronizer(Synchronizer): target_last_known_gen, target_last_known_trans_id = \ self.source._get_replica_gen_and_trans_id( self.target_replica_uid) - logger.debug( - "Soledad source sync info:\n" - " last target gen known to source: %d\n" - " last target trans_id known to source: %s" - % (target_last_known_gen, target_last_known_trans_id)) + logger.debug( + "last known target gen: %d" % target_last_known_gen) + logger.debug( + "last known target trans_id: %s" % target_last_known_trans_id) # validate transaction ids if not changes and target_last_known_gen == target_gen: @@ -180,11 +174,8 @@ class SoledadSynchronizer(Synchronizer): target_last_known_gen, target_last_known_trans_id, self._insert_doc_from_target, ensure_callback=ensure_callback, defer_decryption=defer_decryption) - logger.debug( - "Soledad source sync info after sync exchange:\n" - " source known target gen: %d\n" - " source known target trans_id: %s" - % (new_gen, new_trans_id)) + logger.debug("target gen after sync: %d" % new_gen) + logger.debug("target trans_id after sync: %s" % new_trans_id) info = { "target_replica_uid": self.target_replica_uid, "new_gen": new_gen, @@ -223,7 +214,7 @@ class SoledadSynchronizer(Synchronizer): :return: A deferred which will fire when the sync has been completed. :rtype: twisted.internet.defer.Deferred """ - logger.debug("Completing deferred last step in SYNC...") + logger.debug("completing deferred last step in sync...") # record target synced-up-to generation including applying what we # sent -- cgit v1.2.3 From 0c89333460953413033154e60da2ddb9cc1aed55 Mon Sep 17 00:00:00 2001 From: Victor Shyba Date: Fri, 30 Sep 2016 15:40:54 -0300 Subject: [bug] use % for formatting Otherwise it will put the exception as an additional parameter. --- client/src/leap/soledad/client/sync.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) (limited to 'client/src/leap') diff --git a/client/src/leap/soledad/client/sync.py b/client/src/leap/soledad/client/sync.py index 0c68d100..7ed5f693 100644 --- a/client/src/leap/soledad/client/sync.py +++ b/client/src/leap/soledad/client/sync.py @@ -96,7 +96,7 @@ class SoledadSynchronizer(Synchronizer): sync_target.get_sync_info(self.source._replica_uid) except (errors.DatabaseDoesNotExist, BackendNotReadyError) as e: logger.debug("Database isn't ready on server. Will be created.") - logger.debug("Reason: %s", e.__class__) + logger.debug("Reason: %s" % e.__class__) self.target_replica_uid = None target_gen, target_trans_id = 0, '' target_my_gen, target_my_trans_id = 0, '' -- cgit v1.2.3 From 2b6a0e8d7168b20f86d585ebc4e57b61b1bb9cf9 Mon Sep 17 00:00:00 2001 From: Tulio Casagrande Date: Tue, 4 Oct 2016 18:40:33 -0300 Subject: [bug] remove finalClose from SQLCipherU1DBSync We discovered that class was registering a `finalClose` to be executed on reactor shutdown. On the multiuser scenario, a logout destroys Soledad and should properly terminate everything related to it. That SQLCipherU1DBSync instance was being held even after logout by the reactor so it could call that `finalClose` on shutdown. The `finalClose` only set running to False and set a `shutdownID` that was not used anywhere else, so we removed it and moved setting running to False to the `close` function method. That way we preserve the functionality but let the instance be properly garbage collected on logout. --- client/src/leap/soledad/client/sqlcipher.py | 11 +---------- 1 file changed, 1 insertion(+), 10 deletions(-) (limited to 'client/src/leap') diff --git a/client/src/leap/soledad/client/sqlcipher.py b/client/src/leap/soledad/client/sqlcipher.py index 14d6f5ae..3921c323 100644 --- a/client/src/leap/soledad/client/sqlcipher.py +++ b/client/src/leap/soledad/client/sqlcipher.py @@ -448,7 +448,6 @@ class SQLCipherU1DBSync(SQLCipherDatabase): self.received_docs = [] self.running = False - self.shutdownID = None self._db_handle = None # initialize the main db before scheduling a start @@ -465,8 +464,6 @@ class SQLCipherU1DBSync(SQLCipherDatabase): def _start(self): if not self.running: - self.shutdownID = self._reactor.addSystemEventTrigger( - 'during', 'shutdown', self.finalClose) self.running = True def _initialize_main_db(self): @@ -561,13 +558,6 @@ class SQLCipherU1DBSync(SQLCipherDatabase): # XXX this SHOULD BE a callback return self._get_generation() - def finalClose(self): - """ - This should only be called by the shutdown trigger. - """ - self.shutdownID = None - self.running = False - def close(self): """ Close the syncer and syncdb orderly @@ -578,6 +568,7 @@ class SQLCipherU1DBSync(SQLCipherDatabase): _, syncer = self._syncers[url] syncer.close() del self._syncers[url] + self.running = False class U1DBSQLiteBackend(sqlite_backend.SQLitePartialExpandDatabase): -- cgit v1.2.3