diff --git a/bramble-api/src/main/java/org/briarproject/bramble/util/TimeUtils.java b/bramble-api/src/main/java/org/briarproject/bramble/util/TimeUtils.java new file mode 100644 index 0000000000000000000000000000000000000000..34420a346ccd097c33dfde9ef477d9f8f311257d --- /dev/null +++ b/bramble-api/src/main/java/org/briarproject/bramble/util/TimeUtils.java @@ -0,0 +1,14 @@ +package org.briarproject.bramble.util; + +public class TimeUtils { + + private static final int NANOS_PER_MILLI = 1000 * 1000; + + /** + * Returns the elapsed time in milliseconds since some arbitrary + * starting time. This is only useful for measuring elapsed time. + */ + public static long now() { + return System.nanoTime() / NANOS_PER_MILLI; + } +} diff --git a/bramble-core/src/main/java/org/briarproject/bramble/PoliteExecutor.java b/bramble-core/src/main/java/org/briarproject/bramble/PoliteExecutor.java index 32a3a7b32b8ad3255e70f9fd2926398c4403e793..2ab5e032dffe46a71617bdcbca9837cef06365d2 100644 --- a/bramble-core/src/main/java/org/briarproject/bramble/PoliteExecutor.java +++ b/bramble-core/src/main/java/org/briarproject/bramble/PoliteExecutor.java @@ -5,12 +5,12 @@ import org.briarproject.bramble.api.nullsafety.NotNullByDefault; import java.util.LinkedList; import java.util.Queue; import java.util.concurrent.Executor; -import java.util.logging.Level; import java.util.logging.Logger; import javax.annotation.concurrent.GuardedBy; import static java.util.logging.Level.FINE; +import static org.briarproject.bramble.util.TimeUtils.now; /** * An {@link Executor} that delegates its tasks to another {@link Executor} @@ -20,8 +20,6 @@ import static java.util.logging.Level.FINE; @NotNullByDefault public class PoliteExecutor implements Executor { - private static final Level LOG_LEVEL = FINE; - private final Object lock = new Object(); @GuardedBy("lock") private final Queue<Runnable> queue = new LinkedList<>(); @@ -49,11 +47,11 @@ public class PoliteExecutor implements Executor { @Override public void execute(Runnable r) { - long submitted = System.currentTimeMillis(); + long submitted = now(); Runnable wrapped = () -> { - if (log.isLoggable(LOG_LEVEL)) { - long queued = System.currentTimeMillis() - submitted; - log.log(LOG_LEVEL, "Queue time " + queued + " ms"); + if (log.isLoggable(FINE)) { + long queued = now() - submitted; + log.fine("Queue time " + queued + " ms"); } try { r.run(); diff --git a/bramble-core/src/main/java/org/briarproject/bramble/TimeLoggingExecutor.java b/bramble-core/src/main/java/org/briarproject/bramble/TimeLoggingExecutor.java index c81bf43a7aeb6e6569c624b2831f17ae0bee7f8e..8f5e861a8f2d1d384501bc41a0114cceb5e2f798 100644 --- a/bramble-core/src/main/java/org/briarproject/bramble/TimeLoggingExecutor.java +++ b/bramble-core/src/main/java/org/briarproject/bramble/TimeLoggingExecutor.java @@ -6,16 +6,14 @@ import java.util.concurrent.BlockingQueue; import java.util.concurrent.RejectedExecutionHandler; import java.util.concurrent.ThreadPoolExecutor; import java.util.concurrent.TimeUnit; -import java.util.logging.Level; import java.util.logging.Logger; import static java.util.logging.Level.FINE; +import static org.briarproject.bramble.util.TimeUtils.now; @NotNullByDefault public class TimeLoggingExecutor extends ThreadPoolExecutor { - private static final Level LOG_LEVEL = FINE; - private final Logger log; public TimeLoggingExecutor(String tag, int corePoolSize, int maxPoolSize, @@ -29,15 +27,15 @@ public class TimeLoggingExecutor extends ThreadPoolExecutor { @Override public void execute(Runnable r) { - if (log.isLoggable(LOG_LEVEL)) { - long submitted = System.currentTimeMillis(); + if (log.isLoggable(FINE)) { + long submitted = now(); super.execute(() -> { - long started = System.currentTimeMillis(); + long started = now(); long queued = started - submitted; - log.log(LOG_LEVEL, "Queue time " + queued + " ms"); + log.fine("Queue time " + queued + " ms"); r.run(); - long executing = System.currentTimeMillis() - started; - log.log(LOG_LEVEL, "Execution time " + executing + " ms"); + long executing = now() - started; + log.fine("Execution time " + executing + " ms"); }); } else { super.execute(r); diff --git a/bramble-core/src/main/java/org/briarproject/bramble/crypto/CryptoComponentImpl.java b/bramble-core/src/main/java/org/briarproject/bramble/crypto/CryptoComponentImpl.java index 83e759e3b945850fe9d46ad579ed954f09481460..40b5132f126978a76bfca6a2545907c396be20e7 100644 --- a/bramble-core/src/main/java/org/briarproject/bramble/crypto/CryptoComponentImpl.java +++ b/bramble-core/src/main/java/org/briarproject/bramble/crypto/CryptoComponentImpl.java @@ -30,8 +30,10 @@ import java.util.logging.Logger; import javax.annotation.Nullable; import javax.inject.Inject; +import static java.util.logging.Level.FINE; import static java.util.logging.Level.INFO; import static org.briarproject.bramble.util.ByteUtils.INT_32_BYTES; +import static org.briarproject.bramble.util.TimeUtils.now; @NotNullByDefault class CryptoComponentImpl implements CryptoComponent { @@ -127,16 +129,15 @@ class CryptoComponentImpl implements CryptoComponent { throw new IllegalArgumentException(); if (!(pub instanceof Curve25519PublicKey)) throw new IllegalArgumentException(); - long now = System.currentTimeMillis(); + long start = now(); byte[] secret = curve25519.calculateAgreement(pub.getEncoded(), priv.getEncoded()); // If the shared secret is all zeroes, the public key is invalid byte allZero = 0; for (byte b : secret) allZero |= b; if (allZero == 0) throw new GeneralSecurityException(); - long duration = System.currentTimeMillis() - now; - if (LOG.isLoggable(INFO)) - LOG.info("Deriving shared secret took " + duration + " ms"); + if (LOG.isLoggable(FINE)) + LOG.fine("Deriving shared secret took " + (now() - start) + " ms"); return secret; } diff --git a/bramble-core/src/main/java/org/briarproject/bramble/crypto/ScryptKdf.java b/bramble-core/src/main/java/org/briarproject/bramble/crypto/ScryptKdf.java index b3e567323aa4e6dfa8b1a48765bf802a3cae4aff..f56f0d9dabd81f515e59ac430a995b7af7aa2963 100644 --- a/bramble-core/src/main/java/org/briarproject/bramble/crypto/ScryptKdf.java +++ b/bramble-core/src/main/java/org/briarproject/bramble/crypto/ScryptKdf.java @@ -9,7 +9,9 @@ import java.util.logging.Logger; import javax.inject.Inject; +import static java.util.logging.Level.FINE; import static java.util.logging.Level.INFO; +import static org.briarproject.bramble.util.TimeUtils.now; class ScryptKdf implements PasswordBasedKdf { @@ -50,13 +52,14 @@ class ScryptKdf implements PasswordBasedKdf { @Override public SecretKey deriveKey(String password, byte[] salt, int cost) { - long start = System.currentTimeMillis(); + long start = now(); byte[] passwordBytes = StringUtils.toUtf8(password); SecretKey k = new SecretKey(SCrypt.generate(passwordBytes, salt, cost, BLOCK_SIZE, PARALLELIZATION, SecretKey.LENGTH)); - long duration = System.currentTimeMillis() - start; - if (LOG.isLoggable(INFO)) - LOG.info("Deriving key from password took " + duration + " ms"); + if (LOG.isLoggable(FINE)) { + long duration = now() - start; + LOG.fine("Deriving key from password took " + duration + " ms"); + } return k; } } diff --git a/bramble-core/src/main/java/org/briarproject/bramble/crypto/Sec1KeyParser.java b/bramble-core/src/main/java/org/briarproject/bramble/crypto/Sec1KeyParser.java index edc36c6641fe02c737085994bf9ea05f7a22642c..4e43dad6705c78a05c95d309ba77a0aab10c399b 100644 --- a/bramble-core/src/main/java/org/briarproject/bramble/crypto/Sec1KeyParser.java +++ b/bramble-core/src/main/java/org/briarproject/bramble/crypto/Sec1KeyParser.java @@ -16,7 +16,8 @@ import java.util.logging.Logger; import javax.annotation.concurrent.Immutable; -import static java.util.logging.Level.INFO; +import static java.util.logging.Level.FINE; +import static org.briarproject.bramble.util.TimeUtils.now; /** * A key parser that uses the encoding defined in "SEC 1: Elliptic Curve @@ -48,7 +49,7 @@ class Sec1KeyParser implements KeyParser { throws GeneralSecurityException { // The validation procedure comes from SEC 1, section 3.2.2.1. Note // that SEC 1 parameter names are used below, not RFC 5639 names - long now = System.currentTimeMillis(); + long start = now(); if (encodedKey.length != publicKeyBytes) throw new GeneralSecurityException(); // The first byte must be 0x04 @@ -80,16 +81,15 @@ class Sec1KeyParser implements KeyParser { // Construct a public key from the point (x, y) and the params ECPublicKeyParameters k = new ECPublicKeyParameters(pub, params); PublicKey p = new Sec1PublicKey(k); - long duration = System.currentTimeMillis() - now; - if (LOG.isLoggable(INFO)) - LOG.info("Parsing public key took " + duration + " ms"); + if (LOG.isLoggable(FINE)) + LOG.fine("Parsing public key took " + (now() - start) + " ms"); return p; } @Override public PrivateKey parsePrivateKey(byte[] encodedKey) throws GeneralSecurityException { - long now = System.currentTimeMillis(); + long start = now(); if (encodedKey.length != privateKeyBytes) throw new GeneralSecurityException(); BigInteger d = new BigInteger(1, encodedKey); // Positive signum @@ -99,9 +99,8 @@ class Sec1KeyParser implements KeyParser { // Construct a private key from the private value and the params ECPrivateKeyParameters k = new ECPrivateKeyParameters(d, params); PrivateKey p = new Sec1PrivateKey(k, keyBits); - long duration = System.currentTimeMillis() - now; - if (LOG.isLoggable(INFO)) - LOG.info("Parsing private key took " + duration + " ms"); + if (LOG.isLoggable(FINE)) + LOG.fine("Parsing private key took " + (now() - start) + " ms"); return p; } } diff --git a/bramble-core/src/main/java/org/briarproject/bramble/db/DatabaseComponentImpl.java b/bramble-core/src/main/java/org/briarproject/bramble/db/DatabaseComponentImpl.java index 6f54b32199db44edb215c0769d38d6c25b32a45c..0b478e11997f28db58d0efa643fba6722d94dfb2 100644 --- a/bramble-core/src/main/java/org/briarproject/bramble/db/DatabaseComponentImpl.java +++ b/bramble-core/src/main/java/org/briarproject/bramble/db/DatabaseComponentImpl.java @@ -75,6 +75,7 @@ import static org.briarproject.bramble.api.sync.Group.Visibility.SHARED; import static org.briarproject.bramble.api.sync.ValidationManager.State.DELIVERED; import static org.briarproject.bramble.api.sync.ValidationManager.State.UNKNOWN; import static org.briarproject.bramble.db.DatabaseConstants.MAX_OFFERED_MESSAGES; +import static org.briarproject.bramble.util.TimeUtils.now; @ThreadSafe @NotNullByDefault @@ -125,11 +126,11 @@ class DatabaseComponentImpl<T> implements DatabaseComponent { // Don't allow reentrant locking if (lock.getReadHoldCount() > 0) throw new IllegalStateException(); if (lock.getWriteHoldCount() > 0) throw new IllegalStateException(); - long start = System.currentTimeMillis(); + long start = now(); if (readOnly) lock.readLock().lock(); else lock.writeLock().lock(); if (LOG.isLoggable(FINE)) { - long duration = System.currentTimeMillis() - start; + long duration = now() - start; if (readOnly) LOG.fine("Waited " + duration + " ms for read lock"); else LOG.fine("Waited " + duration + " ms for write lock"); } diff --git a/bramble-core/src/main/java/org/briarproject/bramble/lifecycle/LifecycleManagerImpl.java b/bramble-core/src/main/java/org/briarproject/bramble/lifecycle/LifecycleManagerImpl.java index 0f41cbf211676f5427b56591a24e872c085ecef9..8bbddb739fcd6aca0a44f19abf6cd37d8d00e049 100644 --- a/bramble-core/src/main/java/org/briarproject/bramble/lifecycle/LifecycleManagerImpl.java +++ b/bramble-core/src/main/java/org/briarproject/bramble/lifecycle/LifecycleManagerImpl.java @@ -30,6 +30,7 @@ import javax.annotation.Nullable; import javax.annotation.concurrent.ThreadSafe; import javax.inject.Inject; +import static java.util.logging.Level.FINE; import static java.util.logging.Level.INFO; import static java.util.logging.Level.WARNING; import static org.briarproject.bramble.api.lifecycle.LifecycleManager.LifecycleState.MIGRATING_DATABASE; @@ -43,6 +44,7 @@ import static org.briarproject.bramble.api.lifecycle.LifecycleManager.StartResul import static org.briarproject.bramble.api.lifecycle.LifecycleManager.StartResult.DB_ERROR; import static org.briarproject.bramble.api.lifecycle.LifecycleManager.StartResult.SERVICE_ERROR; import static org.briarproject.bramble.api.lifecycle.LifecycleManager.StartResult.SUCCESS; +import static org.briarproject.bramble.util.TimeUtils.now; @ThreadSafe @NotNullByDefault @@ -101,24 +103,24 @@ class LifecycleManagerImpl implements LifecycleManager, MigrationListener { } private LocalAuthor createLocalAuthor(String nickname) { - long now = System.currentTimeMillis(); + long start = now(); KeyPair keyPair = crypto.generateSignatureKeyPair(); byte[] publicKey = keyPair.getPublic().getEncoded(); byte[] privateKey = keyPair.getPrivate().getEncoded(); LocalAuthor localAuthor = authorFactory .createLocalAuthor(nickname, publicKey, privateKey); - long duration = System.currentTimeMillis() - now; - if (LOG.isLoggable(INFO)) - LOG.info("Creating local author took " + duration + " ms"); + if (LOG.isLoggable(FINE)) + LOG.fine("Creating local author took " + (now() - start) + " ms"); return localAuthor; } private void registerLocalAuthor(LocalAuthor author) throws DbException { - long now = System.currentTimeMillis(); + long start = now(); identityManager.registerLocalAuthor(author); - long duration = System.currentTimeMillis() - now; - if (LOG.isLoggable(INFO)) - LOG.info("Registering local author took " + duration + " ms"); + if (LOG.isLoggable(FINE)) { + LOG.fine("Registering local author took " + (now() - start) + + " ms"); + } } @Override @@ -129,14 +131,14 @@ class LifecycleManagerImpl implements LifecycleManager, MigrationListener { } try { LOG.info("Starting services"); - long start = System.currentTimeMillis(); + long start = now(); boolean reopened = db.open(this); - long duration = System.currentTimeMillis() - start; - if (LOG.isLoggable(INFO)) { + if (LOG.isLoggable(FINE)) { + long duration = now() - start; if (reopened) - LOG.info("Reopening database took " + duration + " ms"); - else LOG.info("Creating database took " + duration + " ms"); + LOG.fine("Reopening database took " + duration + " ms"); + else LOG.fine("Creating database took " + duration + " ms"); } if (nickname != null) { @@ -150,13 +152,12 @@ class LifecycleManagerImpl implements LifecycleManager, MigrationListener { Transaction txn = db.startTransaction(false); try { for (Client c : clients) { - start = System.currentTimeMillis(); + start = now(); c.createLocalState(txn); - duration = System.currentTimeMillis() - start; - if (LOG.isLoggable(INFO)) { - LOG.info("Starting client " + if (LOG.isLoggable(FINE)) { + LOG.fine("Starting client " + c.getClass().getSimpleName() - + " took " + duration + " ms"); + + " took " + (now() - start) + " ms"); } } db.commitTransaction(txn); @@ -164,12 +165,11 @@ class LifecycleManagerImpl implements LifecycleManager, MigrationListener { db.endTransaction(txn); } for (Service s : services) { - start = System.currentTimeMillis(); + start = now(); s.startService(); - duration = System.currentTimeMillis() - start; - if (LOG.isLoggable(INFO)) { - LOG.info("Starting service " + s.getClass().getSimpleName() - + " took " + duration + " ms"); + if (LOG.isLoggable(FINE)) { + LOG.fine("Starting service " + s.getClass().getSimpleName() + + " took " + (now() - start) + " ms"); } } @@ -213,26 +213,24 @@ class LifecycleManagerImpl implements LifecycleManager, MigrationListener { state = STOPPING; eventBus.broadcast(new LifecycleEvent(STOPPING)); for (Service s : services) { - long start = System.currentTimeMillis(); + long start = now(); s.stopService(); - long duration = System.currentTimeMillis() - start; - if (LOG.isLoggable(INFO)) { - LOG.info("Stopping service " + s.getClass().getSimpleName() - + " took " + duration + " ms"); + if (LOG.isLoggable(FINE)) { + LOG.fine("Stopping service " + s.getClass().getSimpleName() + + " took " + (now() - start) + " ms"); } } for (ExecutorService e : executors) { - if (LOG.isLoggable(INFO)) { - LOG.info("Stopping executor " + if (LOG.isLoggable(FINE)) { + LOG.fine("Stopping executor " + e.getClass().getSimpleName()); } e.shutdownNow(); } - long start = System.currentTimeMillis(); + long start = now(); db.close(); - long duration = System.currentTimeMillis() - start; - if (LOG.isLoggable(INFO)) - LOG.info("Closing database took " + duration + " ms"); + if (LOG.isLoggable(FINE)) + LOG.fine("Closing database took " + (now() - start) + " ms"); shutdownLatch.countDown(); } catch (DbException | ServiceException e) { if (LOG.isLoggable(WARNING)) LOG.log(WARNING, e.toString(), e); diff --git a/bramble-core/src/main/java/org/briarproject/bramble/plugin/PluginManagerImpl.java b/bramble-core/src/main/java/org/briarproject/bramble/plugin/PluginManagerImpl.java index 65f66345cee6dc05e3a369048977f976cfc85c6b..a86949de71b9e1fa8c9719823d977489d586a838 100644 --- a/bramble-core/src/main/java/org/briarproject/bramble/plugin/PluginManagerImpl.java +++ b/bramble-core/src/main/java/org/briarproject/bramble/plugin/PluginManagerImpl.java @@ -49,8 +49,10 @@ import java.util.logging.Logger; import javax.annotation.concurrent.ThreadSafe; import javax.inject.Inject; +import static java.util.logging.Level.FINE; import static java.util.logging.Level.INFO; import static java.util.logging.Level.WARNING; +import static org.briarproject.bramble.util.TimeUtils.now; @ThreadSafe @NotNullByDefault @@ -205,12 +207,11 @@ class PluginManagerImpl implements PluginManager, Service { @Override public void run() { try { - long start = System.currentTimeMillis(); + long start = now(); plugin.start(); - long duration = System.currentTimeMillis() - start; - if (LOG.isLoggable(INFO)) { - LOG.info("Starting plugin " + plugin.getId() + " took " + - duration + " ms"); + if (LOG.isLoggable(FINE)) { + LOG.fine("Starting plugin " + plugin.getId() + + " took " + (now() - start) + " ms"); } } catch (PluginException e) { if (LOG.isLoggable(WARNING)) { @@ -243,12 +244,11 @@ class PluginManagerImpl implements PluginManager, Service { // Wait for the plugin to finish starting startLatch.await(); // Stop the plugin - long start = System.currentTimeMillis(); + long start = now(); plugin.stop(); - long duration = System.currentTimeMillis() - start; - if (LOG.isLoggable(INFO)) { - LOG.info("Stopping plugin " + plugin.getId() - + " took " + duration + " ms"); + if (LOG.isLoggable(FINE)) { + LOG.fine("Stopping plugin " + plugin.getId() + + " took " + (now() - start) + " ms"); } } catch (InterruptedException e) { LOG.warning("Interrupted while waiting for plugin to stop"); diff --git a/briar-android/src/main/java/org/briarproject/briar/android/BriarApplicationImpl.java b/briar-android/src/main/java/org/briarproject/briar/android/BriarApplicationImpl.java index a2ff968a7e61c7df5f00bccc6c2325ad3411d404..bbb8a568cafb21ba2884ef9a1408dbfb541e1c53 100644 --- a/briar-android/src/main/java/org/briarproject/briar/android/BriarApplicationImpl.java +++ b/briar-android/src/main/java/org/briarproject/briar/android/BriarApplicationImpl.java @@ -25,6 +25,7 @@ import java.util.logging.Handler; import java.util.logging.LogRecord; import java.util.logging.Logger; +import static java.util.logging.Level.FINE; import static java.util.logging.Level.INFO; import static org.acra.ReportField.ANDROID_VERSION; import static org.acra.ReportField.APP_VERSION_CODE; @@ -101,7 +102,7 @@ public class BriarApplicationImpl extends Application } } rootLogger.addHandler(logHandler); - rootLogger.setLevel(INFO); + rootLogger.setLevel(IS_DEBUG_BUILD || IS_BETA_BUILD ? FINE : INFO); LOG.info("Created"); diff --git a/briar-android/src/main/java/org/briarproject/briar/android/NetworkUsageLogger.java b/briar-android/src/main/java/org/briarproject/briar/android/NetworkUsageLogger.java index dcf500cbf644ea264279efed844c36818b84b898..5e700baccc9c4bdf7e296be0e221a19eacb0412b 100644 --- a/briar-android/src/main/java/org/briarproject/briar/android/NetworkUsageLogger.java +++ b/briar-android/src/main/java/org/briarproject/briar/android/NetworkUsageLogger.java @@ -4,11 +4,11 @@ import android.net.TrafficStats; import android.os.Process; import org.briarproject.bramble.api.lifecycle.Service; -import org.briarproject.bramble.api.lifecycle.ServiceException; import java.util.logging.Logger; import static java.util.logging.Level.INFO; +import static org.briarproject.bramble.util.TimeUtils.now; class NetworkUsageLogger implements Service { @@ -18,17 +18,17 @@ class NetworkUsageLogger implements Service { private volatile long startTime, rxBytes, txBytes; @Override - public void startService() throws ServiceException { - startTime = System.currentTimeMillis(); + public void startService() { + startTime = now(); int uid = Process.myUid(); rxBytes = TrafficStats.getUidRxBytes(uid); txBytes = TrafficStats.getUidTxBytes(uid); } @Override - public void stopService() throws ServiceException { + public void stopService() { if (LOG.isLoggable(INFO)) { - long sessionDuration = System.currentTimeMillis() - startTime; + long sessionDuration = now() - startTime; int uid = Process.myUid(); long rx = TrafficStats.getUidRxBytes(uid) - rxBytes; long tx = TrafficStats.getUidTxBytes(uid) - txBytes; diff --git a/briar-android/src/main/java/org/briarproject/briar/android/blog/BaseControllerImpl.java b/briar-android/src/main/java/org/briarproject/briar/android/blog/BaseControllerImpl.java index e2b588dfa00ff7c0ac9b50958efd0f164a1e94fa..6bcef86c657a3d7f9ac3b989918409df4c2121a6 100644 --- a/briar-android/src/main/java/org/briarproject/briar/android/blog/BaseControllerImpl.java +++ b/briar-android/src/main/java/org/briarproject/briar/android/blog/BaseControllerImpl.java @@ -32,8 +32,9 @@ import java.util.logging.Logger; import javax.annotation.Nullable; -import static java.util.logging.Level.INFO; +import static java.util.logging.Level.FINE; import static java.util.logging.Level.WARNING; +import static org.briarproject.bramble.util.TimeUtils.now; import static org.briarproject.briar.util.HtmlUtils.ARTICLE; @MethodsNotNullByDefault @@ -109,22 +110,20 @@ abstract class BaseControllerImpl extends DbControllerImpl } Collection<BlogPostItem> loadItems(GroupId groupId) throws DbException { - long now = System.currentTimeMillis(); + long start = now(); Collection<BlogPostHeader> headers = blogManager.getPostHeaders(groupId); - long duration = System.currentTimeMillis() - now; - if (LOG.isLoggable(INFO)) - LOG.info("Loading headers took " + duration + " ms"); + if (LOG.isLoggable(FINE)) + LOG.fine("Loading headers took " + (now() - start) + " ms"); Collection<BlogPostItem> items = new ArrayList<>(headers.size()); - now = System.currentTimeMillis(); + start = now(); for (BlogPostHeader h : headers) { headerCache.put(h.getId(), h); BlogPostItem item = getItem(h); items.add(item); } - duration = System.currentTimeMillis() - now; - if (LOG.isLoggable(INFO)) - LOG.info("Loading bodies took " + duration + " ms"); + if (LOG.isLoggable(FINE)) + LOG.fine("Loading bodies took " + (now() - start) + " ms"); return items; } @@ -140,11 +139,10 @@ abstract class BaseControllerImpl extends DbControllerImpl } runOnDbThread(() -> { try { - long now = System.currentTimeMillis(); + long start = now(); BlogPostItem item = getItem(header); - long duration = System.currentTimeMillis() - now; - if (LOG.isLoggable(INFO)) - LOG.info("Loading body took " + duration + " ms"); + if (LOG.isLoggable(FINE)) + LOG.fine("Loading body took " + (now() - start) + " ms"); handler.onResult(item); } catch (DbException e) { if (LOG.isLoggable(WARNING)) @@ -166,12 +164,11 @@ abstract class BaseControllerImpl extends DbControllerImpl } runOnDbThread(() -> { try { - long now = System.currentTimeMillis(); + long start = now(); BlogPostHeader header1 = getPostHeader(g, m); BlogPostItem item = getItem(header1); - long duration = System.currentTimeMillis() - now; - if (LOG.isLoggable(INFO)) - LOG.info("Loading post took " + duration + " ms"); + if (LOG.isLoggable(FINE)) + LOG.fine("Loading post took " + (now() - start) + " ms"); handler.onResult(item); } catch (DbException e) { if (LOG.isLoggable(WARNING)) diff --git a/briar-android/src/main/java/org/briarproject/briar/android/blog/BlogControllerImpl.java b/briar-android/src/main/java/org/briarproject/briar/android/blog/BlogControllerImpl.java index be7b8ff2222cd4fc230f6393f7dbd193efc8bd87..323dda2e5a44cba85a5a8ef2aee52e73ce45594f 100644 --- a/briar-android/src/main/java/org/briarproject/briar/android/blog/BlogControllerImpl.java +++ b/briar-android/src/main/java/org/briarproject/briar/android/blog/BlogControllerImpl.java @@ -35,8 +35,9 @@ import java.util.logging.Logger; import javax.inject.Inject; -import static java.util.logging.Level.INFO; +import static java.util.logging.Level.FINE; import static java.util.logging.Level.WARNING; +import static org.briarproject.bramble.util.TimeUtils.now; @MethodsNotNullByDefault @ParametersNotNullByDefault @@ -154,15 +155,14 @@ class BlogControllerImpl extends BaseControllerImpl if (groupId == null) throw new IllegalStateException(); runOnDbThread(() -> { try { - long now = System.currentTimeMillis(); + long start = now(); LocalAuthor a = identityManager.getLocalAuthor(); Blog b = blogManager.getBlog(groupId); boolean ours = a.getId().equals(b.getAuthor().getId()); boolean removable = blogManager.canBeRemoved(b); BlogItem blog = new BlogItem(b, ours, removable); - long duration = System.currentTimeMillis() - now; - if (LOG.isLoggable(INFO)) - LOG.info("Loading blog took " + duration + " ms"); + if (LOG.isLoggable(FINE)) + LOG.fine("Loading blog took " + (now() - start) + " ms"); handler.onResult(blog); } catch (DbException e) { if (LOG.isLoggable(WARNING)) @@ -177,12 +177,11 @@ class BlogControllerImpl extends BaseControllerImpl if (groupId == null) throw new IllegalStateException(); runOnDbThread(() -> { try { - long now = System.currentTimeMillis(); + long start = now(); Blog b = blogManager.getBlog(groupId); blogManager.removeBlog(b); - long duration = System.currentTimeMillis() - now; - if (LOG.isLoggable(INFO)) - LOG.info("Removing blog took " + duration + " ms"); + if (LOG.isLoggable(FINE)) + LOG.fine("Removing blog took " + (now() - start) + " ms"); handler.onResult(null); } catch (DbException e) { if (LOG.isLoggable(WARNING)) diff --git a/briar-android/src/main/java/org/briarproject/briar/android/blog/FeedControllerImpl.java b/briar-android/src/main/java/org/briarproject/briar/android/blog/FeedControllerImpl.java index 1118fe654da6c0fd0a44d32b04717dbdbedb9525..08134e5bfafbe26cfb3d8e4f434cfcaa295c9a78 100644 --- a/briar-android/src/main/java/org/briarproject/briar/android/blog/FeedControllerImpl.java +++ b/briar-android/src/main/java/org/briarproject/briar/android/blog/FeedControllerImpl.java @@ -26,8 +26,9 @@ import java.util.logging.Logger; import javax.inject.Inject; -import static java.util.logging.Level.INFO; +import static java.util.logging.Level.FINE; import static java.util.logging.Level.WARNING; +import static org.briarproject.bramble.util.TimeUtils.now; import static org.briarproject.briar.api.blog.BlogManager.CLIENT_ID; @MethodsNotNullByDefault @@ -99,7 +100,7 @@ class FeedControllerImpl extends BaseControllerImpl ResultExceptionHandler<Collection<BlogPostItem>, DbException> handler) { runOnDbThread(() -> { try { - long now = System.currentTimeMillis(); + long start = now(); Collection<BlogPostItem> posts = new ArrayList<>(); for (Blog b : blogManager.getBlogs()) { try { @@ -109,9 +110,10 @@ class FeedControllerImpl extends BaseControllerImpl LOG.log(WARNING, e.toString(), e); } } - long duration = System.currentTimeMillis() - now; - if (LOG.isLoggable(INFO)) - LOG.info("Loading all posts took " + duration + " ms"); + if (LOG.isLoggable(FINE)) { + long duration = now() - start; + LOG.fine("Loading all posts took " + duration + " ms"); + } handler.onResult(posts); } catch (DbException e) { if (LOG.isLoggable(WARNING)) LOG.log(WARNING, e.toString(), e); @@ -125,12 +127,12 @@ class FeedControllerImpl extends BaseControllerImpl ResultExceptionHandler<Blog, DbException> handler) { runOnDbThread(() -> { try { - long now = System.currentTimeMillis(); + long start = now(); Author a = identityManager.getLocalAuthor(); Blog b = blogManager.getPersonalBlog(a); - long duration = System.currentTimeMillis() - now; - if (LOG.isLoggable(INFO)) - LOG.info("Loading blog took " + duration + " ms"); + long duration = now() - start; + if (LOG.isLoggable(FINE)) + LOG.fine("Loading blog took " + duration + " ms"); handler.onResult(b); } catch (DbException e) { if (LOG.isLoggable(WARNING)) LOG.log(WARNING, e.toString(), e); diff --git a/briar-android/src/main/java/org/briarproject/briar/android/blog/WriteBlogPostActivity.java b/briar-android/src/main/java/org/briarproject/briar/android/blog/WriteBlogPostActivity.java index 918c6def21fbcda550b06f00e4792ca51bed482b..7f11558e051a4d59f9ffe302c5376c6adb2b4872 100644 --- a/briar-android/src/main/java/org/briarproject/briar/android/blog/WriteBlogPostActivity.java +++ b/briar-android/src/main/java/org/briarproject/briar/android/blog/WriteBlogPostActivity.java @@ -142,11 +142,11 @@ public class WriteBlogPostActivity extends BriarActivity private void storePost(String body) { runOnDbThread(() -> { - long now = System.currentTimeMillis(); + long timestamp = System.currentTimeMillis(); try { LocalAuthor author = identityManager.getLocalAuthor(); BlogPost p = blogPostFactory - .createBlogPost(groupId, now, null, author, body); + .createBlogPost(groupId, timestamp, null, author, body); blogManager.addLocalPost(p); postPublished(); } catch (DbException | GeneralSecurityException diff --git a/briar-android/src/main/java/org/briarproject/briar/android/contact/ContactListFragment.java b/briar-android/src/main/java/org/briarproject/briar/android/contact/ContactListFragment.java index d404ea47a40b6894aa481838c1b8b8790a1c65cf..35999ca56bb935e13c1e1cbe9cfa72aec3097df8 100644 --- a/briar-android/src/main/java/org/briarproject/briar/android/contact/ContactListFragment.java +++ b/briar-android/src/main/java/org/briarproject/briar/android/contact/ContactListFragment.java @@ -59,8 +59,9 @@ import javax.inject.Inject; import static android.support.v4.app.ActivityOptionsCompat.makeSceneTransitionAnimation; import static android.support.v4.view.ViewCompat.getTransitionName; -import static java.util.logging.Level.INFO; +import static java.util.logging.Level.FINE; import static java.util.logging.Level.WARNING; +import static org.briarproject.bramble.util.TimeUtils.now; import static org.briarproject.briar.android.contact.ConversationActivity.CONTACT_ID; @MethodsNotNullByDefault @@ -194,7 +195,7 @@ public class ContactListFragment extends BaseFragment implements EventListener { int revision = adapter.getRevision(); listener.runOnDbThread(() -> { try { - long now = System.currentTimeMillis(); + long start = now(); List<ContactListItem> contacts = new ArrayList<>(); for (Contact c : contactManager.getActiveContacts()) { try { @@ -208,9 +209,8 @@ public class ContactListFragment extends BaseFragment implements EventListener { // Continue } } - long duration = System.currentTimeMillis() - now; - if (LOG.isLoggable(INFO)) - LOG.info("Full load took " + duration + " ms"); + if (LOG.isLoggable(FINE)) + LOG.fine("Full load took " + (now() - start) + " ms"); displayContacts(revision, contacts); } catch (DbException e) { if (LOG.isLoggable(WARNING)) LOG.log(WARNING, e.toString(), e); diff --git a/briar-android/src/main/java/org/briarproject/briar/android/contact/ConversationActivity.java b/briar-android/src/main/java/org/briarproject/briar/android/contact/ConversationActivity.java index f926fe54d7daf59d4009d2a22979be87a2dde25e..70b8d1ccccab751ec72008ace9164386458f49eb 100644 --- a/briar-android/src/main/java/org/briarproject/briar/android/contact/ConversationActivity.java +++ b/briar-android/src/main/java/org/briarproject/briar/android/contact/ConversationActivity.java @@ -104,8 +104,10 @@ import uk.co.samuelwall.materialtaptargetprompt.MaterialTapTargetPrompt.PromptSt import static android.support.v4.view.ViewCompat.setTransitionName; import static android.support.v7.util.SortedList.INVALID_POSITION; import static android.widget.Toast.LENGTH_SHORT; +import static java.util.logging.Level.FINE; import static java.util.logging.Level.INFO; import static java.util.logging.Level.WARNING; +import static org.briarproject.bramble.util.TimeUtils.now; import static org.briarproject.briar.android.activity.RequestCodes.REQUEST_INTRODUCTION; import static org.briarproject.briar.android.settings.SettingsFragment.SETTINGS_NAMESPACE; import static org.briarproject.briar.android.util.UiUtils.getAvatarTransitionName; @@ -290,15 +292,14 @@ public class ConversationActivity extends BriarActivity private void loadContactDetailsAndMessages() { runOnDbThread(() -> { try { - long now = System.currentTimeMillis(); + long start = now(); if (contactName == null || contactAuthorId == null) { Contact contact = contactManager.getContact(contactId); contactName = contact.getAuthor().getName(); contactAuthorId = contact.getAuthor().getId(); } - long duration = System.currentTimeMillis() - now; - if (LOG.isLoggable(INFO)) - LOG.info("Loading contact took " + duration + " ms"); + if (LOG.isLoggable(FINE)) + LOG.fine("Loading contact took " + (now() - start) + " ms"); loadMessages(); displayContactDetails(); } catch (NoSuchContactException e) { @@ -340,7 +341,7 @@ public class ConversationActivity extends BriarActivity int revision = adapter.getRevision(); runOnDbThread(() -> { try { - long now = System.currentTimeMillis(); + long start = now(); Collection<PrivateMessageHeader> headers = messagingManager.getMessageHeaders(contactId); Collection<IntroductionMessage> introductions = @@ -357,9 +358,10 @@ public class ConversationActivity extends BriarActivity invitations.addAll(forumInvitations); invitations.addAll(blogInvitations); invitations.addAll(groupInvitations); - long duration = System.currentTimeMillis() - now; - if (LOG.isLoggable(INFO)) - LOG.info("Loading messages took " + duration + " ms"); + if (LOG.isLoggable(FINE)) { + long duration = now() - start; + LOG.fine("Loading messages took " + duration + " ms"); + } displayMessages(revision, headers, introductions, invitations); } catch (NoSuchContactException e) { finishOnUiThread(); @@ -438,11 +440,10 @@ public class ConversationActivity extends BriarActivity private void loadMessageBody(MessageId m) { runOnDbThread(() -> { try { - long now = System.currentTimeMillis(); + long start = now(); String body = messagingManager.getMessageBody(m); - long duration = System.currentTimeMillis() - now; - if (LOG.isLoggable(INFO)) - LOG.info("Loading body took " + duration + " ms"); + if (LOG.isLoggable(FINE)) + LOG.fine("Loading body took " + (now() - start) + " ms"); displayMessageBody(m, body); } catch (DbException e) { if (LOG.isLoggable(WARNING)) LOG.log(WARNING, e.toString(), e); @@ -689,11 +690,10 @@ public class ConversationActivity extends BriarActivity private void storeMessage(PrivateMessage m, String body) { runOnDbThread(() -> { try { - long now = System.currentTimeMillis(); + long start = now(); messagingManager.addLocalMessage(m); - long duration = System.currentTimeMillis() - now; - if (LOG.isLoggable(INFO)) - LOG.info("Storing message took " + duration + " ms"); + if (LOG.isLoggable(FINE)) + LOG.fine("Storing message took " + (now() - start) + " ms"); Message message = m.getMessage(); PrivateMessageHeader h = new PrivateMessageHeader( message.getId(), message.getGroupId(), @@ -816,11 +816,10 @@ public class ConversationActivity extends BriarActivity private void markMessageRead(GroupId g, MessageId m) { runOnDbThread(() -> { try { - long now = System.currentTimeMillis(); + long start = now(); messagingManager.setReadFlag(g, m, true); - long duration = System.currentTimeMillis() - now; - if (LOG.isLoggable(INFO)) - LOG.info("Marking read took " + duration + " ms"); + if (LOG.isLoggable(FINE)) + LOG.fine("Marking read took " + (now() - start) + " ms"); } catch (DbException e) { if (LOG.isLoggable(WARNING)) LOG.log(WARNING, e.toString(), e); } diff --git a/briar-android/src/main/java/org/briarproject/briar/android/forum/CreateForumActivity.java b/briar-android/src/main/java/org/briarproject/briar/android/forum/CreateForumActivity.java index 2015be8db47c736b58688f8d763281eb79933d12..67a25c1dfd431fe267d92a137f61ec70b018d908 100644 --- a/briar-android/src/main/java/org/briarproject/briar/android/forum/CreateForumActivity.java +++ b/briar-android/src/main/java/org/briarproject/briar/android/forum/CreateForumActivity.java @@ -28,8 +28,9 @@ import javax.inject.Inject; import static android.view.View.GONE; import static android.view.View.VISIBLE; import static android.widget.Toast.LENGTH_LONG; -import static java.util.logging.Level.INFO; +import static java.util.logging.Level.FINE; import static java.util.logging.Level.WARNING; +import static org.briarproject.bramble.util.TimeUtils.now; import static org.briarproject.briar.api.forum.ForumConstants.MAX_FORUM_NAME_LENGTH; @MethodsNotNullByDefault @@ -122,11 +123,10 @@ public class CreateForumActivity extends BriarActivity { private void storeForum(String name) { runOnDbThread(() -> { try { - long now = System.currentTimeMillis(); + long start = now(); Forum f = forumManager.addForum(name); - long duration = System.currentTimeMillis() - now; - if (LOG.isLoggable(INFO)) - LOG.info("Storing forum took " + duration + " ms"); + if (LOG.isLoggable(FINE)) + LOG.fine("Storing forum took " + (now() - start) + " ms"); displayForum(f); } catch (DbException e) { if (LOG.isLoggable(WARNING)) LOG.log(WARNING, e.toString(), e); diff --git a/briar-android/src/main/java/org/briarproject/briar/android/forum/ForumListFragment.java b/briar-android/src/main/java/org/briarproject/briar/android/forum/ForumListFragment.java index af52ab94360633ef447ddf9028dbcb4f930ee773..dbd91ddec4b03957c80088493fbd7d49203b6a31 100644 --- a/briar-android/src/main/java/org/briarproject/briar/android/forum/ForumListFragment.java +++ b/briar-android/src/main/java/org/briarproject/briar/android/forum/ForumListFragment.java @@ -44,8 +44,9 @@ import javax.annotation.Nullable; import javax.inject.Inject; import static android.support.design.widget.Snackbar.LENGTH_INDEFINITE; -import static java.util.logging.Level.INFO; +import static java.util.logging.Level.FINE; import static java.util.logging.Level.WARNING; +import static org.briarproject.bramble.util.TimeUtils.now; import static org.briarproject.briar.api.forum.ForumManager.CLIENT_ID; @MethodsNotNullByDefault @@ -157,7 +158,7 @@ public class ForumListFragment extends BaseEventFragment implements int revision = adapter.getRevision(); listener.runOnDbThread(() -> { try { - long now = System.currentTimeMillis(); + long start = now(); Collection<ForumListItem> forums = new ArrayList<>(); for (Forum f : forumManager.getForums()) { try { @@ -168,9 +169,8 @@ public class ForumListFragment extends BaseEventFragment implements // Continue } } - long duration = System.currentTimeMillis() - now; - if (LOG.isLoggable(INFO)) - LOG.info("Full load took " + duration + " ms"); + if (LOG.isLoggable(FINE)) + LOG.fine("Full load took " + (now() - start) + " ms"); displayForums(revision, forums); } catch (DbException e) { if (LOG.isLoggable(WARNING)) LOG.log(WARNING, e.toString(), e); @@ -194,11 +194,12 @@ public class ForumListFragment extends BaseEventFragment implements private void loadAvailableForums() { listener.runOnDbThread(() -> { try { - long now = System.currentTimeMillis(); + long start = now(); int available = forumSharingManager.getInvitations().size(); - long duration = System.currentTimeMillis() - now; - if (LOG.isLoggable(INFO)) - LOG.info("Loading available took " + duration + " ms"); + if (LOG.isLoggable(FINE)) { + long duration = now() - start; + LOG.fine("Loading available took " + duration + " ms"); + } displayAvailableForums(available); } catch (DbException e) { if (LOG.isLoggable(WARNING)) LOG.log(WARNING, e.toString(), e); diff --git a/briar-android/src/main/java/org/briarproject/briar/android/login/PasswordControllerImpl.java b/briar-android/src/main/java/org/briarproject/briar/android/login/PasswordControllerImpl.java index 121b7e119206f6e821db2bcd8868333f0420de49..04e4064200de0fd7e24c80ba821d35e693d4f8df 100644 --- a/briar-android/src/main/java/org/briarproject/briar/android/login/PasswordControllerImpl.java +++ b/briar-android/src/main/java/org/briarproject/briar/android/login/PasswordControllerImpl.java @@ -17,7 +17,8 @@ import java.util.logging.Logger; import javax.inject.Inject; -import static java.util.logging.Level.INFO; +import static java.util.logging.Level.FINE; +import static org.briarproject.bramble.util.TimeUtils.now; @NotNullByDefault public class PasswordControllerImpl extends ConfigControllerImpl @@ -86,11 +87,10 @@ public class PasswordControllerImpl extends ConfigControllerImpl @CryptoExecutor String encryptDatabaseKey(SecretKey key, String password) { - long now = System.currentTimeMillis(); + long start = now(); byte[] encrypted = crypto.encryptWithPassword(key.getBytes(), password); - long duration = System.currentTimeMillis() - now; - if (LOG.isLoggable(INFO)) - LOG.info("Key derivation took " + duration + " ms"); + if (LOG.isLoggable(FINE)) + LOG.fine("Key derivation took " + (now() - start) + " ms"); return StringUtils.toHexString(encrypted); } } diff --git a/briar-android/src/main/java/org/briarproject/briar/android/privategroup/list/GroupListControllerImpl.java b/briar-android/src/main/java/org/briarproject/briar/android/privategroup/list/GroupListControllerImpl.java index 8824923fb10ca92f6d8fda44804cd0010e0798ba..9b636ce2f8f69cc407650d71dcd1a7b42563af88 100644 --- a/briar-android/src/main/java/org/briarproject/briar/android/privategroup/list/GroupListControllerImpl.java +++ b/briar-android/src/main/java/org/briarproject/briar/android/privategroup/list/GroupListControllerImpl.java @@ -36,8 +36,9 @@ import java.util.logging.Logger; import javax.inject.Inject; -import static java.util.logging.Level.INFO; +import static java.util.logging.Level.FINE; import static java.util.logging.Level.WARNING; +import static org.briarproject.bramble.util.TimeUtils.now; import static org.briarproject.briar.api.privategroup.PrivateGroupManager.CLIENT_ID; @MethodsNotNullByDefault @@ -147,7 +148,7 @@ class GroupListControllerImpl extends DbControllerImpl ResultExceptionHandler<Collection<GroupItem>, DbException> handler) { runOnDbThread(() -> { try { - long now = System.currentTimeMillis(); + long start = now(); Collection<PrivateGroup> groups = groupManager.getPrivateGroups(); List<GroupItem> items = new ArrayList<>(groups.size()); @@ -161,9 +162,8 @@ class GroupListControllerImpl extends DbControllerImpl // Continue } } - long duration = System.currentTimeMillis() - now; - if (LOG.isLoggable(INFO)) - LOG.info("Loading groups took " + duration + " ms"); + if (LOG.isLoggable(FINE)) + LOG.fine("Loading groups took " + (now() - start) + " ms"); handler.onResult(items); } catch (DbException e) { if (LOG.isLoggable(WARNING)) LOG.log(WARNING, e.toString(), e); @@ -176,11 +176,10 @@ class GroupListControllerImpl extends DbControllerImpl public void removeGroup(GroupId g, ExceptionHandler<DbException> handler) { runOnDbThread(() -> { try { - long now = System.currentTimeMillis(); + long start = now(); groupManager.removePrivateGroup(g); - long duration = System.currentTimeMillis() - now; - if (LOG.isLoggable(INFO)) - LOG.info("Removing group took " + duration + " ms"); + if (LOG.isLoggable(FINE)) + LOG.fine("Removing group took " + (now() - start) + " ms"); } catch (DbException e) { if (LOG.isLoggable(WARNING)) LOG.log(WARNING, e.toString(), e); handler.onException(e); diff --git a/briar-android/src/main/java/org/briarproject/briar/android/settings/SettingsFragment.java b/briar-android/src/main/java/org/briarproject/briar/android/settings/SettingsFragment.java index 00546afd47b83630ddd4c96573bcc014b1a24271..6c6ff69531e5c0615c77077d3bc80506e239d74d 100644 --- a/briar-android/src/main/java/org/briarproject/briar/android/settings/SettingsFragment.java +++ b/briar-android/src/main/java/org/briarproject/briar/android/settings/SettingsFragment.java @@ -59,11 +59,13 @@ import static android.provider.Settings.EXTRA_CHANNEL_ID; import static android.provider.Settings.System.DEFAULT_NOTIFICATION_URI; import static android.support.v4.view.ViewCompat.LAYOUT_DIRECTION_LTR; import static android.widget.Toast.LENGTH_SHORT; +import static java.util.logging.Level.FINE; import static java.util.logging.Level.INFO; import static java.util.logging.Level.WARNING; import static org.briarproject.bramble.api.plugin.BluetoothConstants.PREF_BT_ENABLE; import static org.briarproject.bramble.api.plugin.TorConstants.PREF_TOR_NETWORK; import static org.briarproject.bramble.api.plugin.TorConstants.PREF_TOR_NETWORK_ALWAYS; +import static org.briarproject.bramble.util.TimeUtils.now; import static org.briarproject.briar.android.TestingConstants.IS_DEBUG_BUILD; import static org.briarproject.briar.android.activity.RequestCodes.REQUEST_RINGTONE; import static org.briarproject.briar.android.navdrawer.NavDrawerActivity.INTENT_SIGN_OUT; @@ -242,14 +244,15 @@ public class SettingsFragment extends PreferenceFragmentCompat private void loadSettings() { listener.runOnDbThread(() -> { try { - long now = System.currentTimeMillis(); + long start = now(); settings = settingsManager.getSettings(SETTINGS_NAMESPACE); Settings btSettings = settingsManager.getSettings(BT_NAMESPACE); Settings torSettings = settingsManager.getSettings(TOR_NAMESPACE); - long duration = System.currentTimeMillis() - now; - if (LOG.isLoggable(INFO)) - LOG.info("Loading settings took " + duration + " ms"); + if (LOG.isLoggable(FINE)) { + long duration = now() - start; + LOG.fine("Loading settings took " + duration + " ms"); + } boolean btSetting = btSettings.getBoolean(PREF_BT_ENABLE, false); int torSetting = torSettings.getInt(PREF_TOR_NETWORK, @@ -435,11 +438,12 @@ public class SettingsFragment extends PreferenceFragmentCompat try { Settings s = new Settings(); s.putInt(PREF_TOR_NETWORK, torSetting); - long now = System.currentTimeMillis(); + long start = now(); settingsManager.mergeSettings(s, TOR_NAMESPACE); - long duration = System.currentTimeMillis() - now; - if (LOG.isLoggable(INFO)) - LOG.info("Merging settings took " + duration + " ms"); + if (LOG.isLoggable(FINE)) { + long duration = now() - start; + LOG.fine("Merging settings took " + duration + " ms"); + } } catch (DbException e) { if (LOG.isLoggable(WARNING)) LOG.log(WARNING, e.toString(), e); } @@ -451,11 +455,12 @@ public class SettingsFragment extends PreferenceFragmentCompat try { Settings s = new Settings(); s.putBoolean(PREF_BT_ENABLE, btSetting); - long now = System.currentTimeMillis(); + long start = now(); settingsManager.mergeSettings(s, BT_NAMESPACE); - long duration = System.currentTimeMillis() - now; - if (LOG.isLoggable(INFO)) - LOG.info("Merging settings took " + duration + " ms"); + if (LOG.isLoggable(FINE)) { + long duration = now() - start; + LOG.fine("Merging settings took " + duration + " ms"); + } } catch (DbException e) { if (LOG.isLoggable(WARNING)) LOG.log(WARNING, e.toString(), e); } @@ -465,11 +470,12 @@ public class SettingsFragment extends PreferenceFragmentCompat private void storeSettings(Settings settings) { listener.runOnDbThread(() -> { try { - long now = System.currentTimeMillis(); + long start = now(); settingsManager.mergeSettings(settings, SETTINGS_NAMESPACE); - long duration = System.currentTimeMillis() - now; - if (LOG.isLoggable(INFO)) - LOG.info("Merging settings took " + duration + " ms"); + if (LOG.isLoggable(FINE)) { + long duration = now() - start; + LOG.fine("Merging settings took " + duration + " ms"); + } } catch (DbException e) { if (LOG.isLoggable(WARNING)) LOG.log(WARNING, e.toString(), e); } diff --git a/briar-android/src/main/java/org/briarproject/briar/android/sharing/InvitationControllerImpl.java b/briar-android/src/main/java/org/briarproject/briar/android/sharing/InvitationControllerImpl.java index ad584b03dab5172ab0623ec97d44b3b3217ff720..e457a60a4a505e174e014e29293ce15c19e88c53 100644 --- a/briar-android/src/main/java/org/briarproject/briar/android/sharing/InvitationControllerImpl.java +++ b/briar-android/src/main/java/org/briarproject/briar/android/sharing/InvitationControllerImpl.java @@ -24,8 +24,9 @@ import java.util.Collection; import java.util.concurrent.Executor; import java.util.logging.Logger; -import static java.util.logging.Level.INFO; +import static java.util.logging.Level.FINE; import static java.util.logging.Level.WARNING; +import static org.briarproject.bramble.util.TimeUtils.now; @MethodsNotNullByDefault @ParametersNotNullByDefault @@ -94,13 +95,13 @@ public abstract class InvitationControllerImpl<I extends InvitationItem> public void loadInvitations(boolean clear, ResultExceptionHandler<Collection<I>, DbException> handler) { runOnDbThread(() -> { - Collection<I> invitations = new ArrayList<>(); try { - long now = System.currentTimeMillis(); - invitations.addAll(getInvitations()); - long duration = System.currentTimeMillis() - now; - if (LOG.isLoggable(INFO)) - LOG.info("Loading invitations took " + duration + " ms"); + long start = now(); + Collection<I> invitations = new ArrayList<>(getInvitations()); + if (LOG.isLoggable(FINE)) { + long duration = now() - start; + LOG.fine("Loading invitations took " + duration + " ms"); + } handler.onResult(invitations); } catch (DbException e) { if (LOG.isLoggable(WARNING)) LOG.log(WARNING, e.toString(), e); diff --git a/briar-android/src/main/java/org/briarproject/briar/android/threaded/ThreadListControllerImpl.java b/briar-android/src/main/java/org/briarproject/briar/android/threaded/ThreadListControllerImpl.java index 11929640ed5008a11431051ca25584536221bd6b..deb769c1423cd8f81a1d41e4d87fe9c10e205bbc 100644 --- a/briar-android/src/main/java/org/briarproject/briar/android/threaded/ThreadListControllerImpl.java +++ b/briar-android/src/main/java/org/briarproject/briar/android/threaded/ThreadListControllerImpl.java @@ -34,8 +34,10 @@ import java.util.concurrent.ConcurrentHashMap; import java.util.concurrent.Executor; import java.util.logging.Logger; +import static java.util.logging.Level.FINE; import static java.util.logging.Level.INFO; import static java.util.logging.Level.WARNING; +import static org.briarproject.bramble.util.TimeUtils.now; @MethodsNotNullByDefault @ParametersNotNullByDefault @@ -131,11 +133,10 @@ public abstract class ThreadListControllerImpl<G extends NamedGroup, I extends T checkGroupId(); runOnDbThread(() -> { try { - long now = System.currentTimeMillis(); + long start = now(); G groupItem = loadNamedGroup(); - long duration = System.currentTimeMillis() - now; - if (LOG.isLoggable(INFO)) - LOG.info("Loading group took " + duration + " ms"); + if (LOG.isLoggable(FINE)) + LOG.fine("Loading group took " + (now() - start) + " ms"); handler.onResult(groupItem); } catch (DbException e) { if (LOG.isLoggable(WARNING)) @@ -155,23 +156,21 @@ public abstract class ThreadListControllerImpl<G extends NamedGroup, I extends T runOnDbThread(() -> { try { // Load headers - long now = System.currentTimeMillis(); + long start = now(); Collection<H> headers = loadHeaders(); - long duration = System.currentTimeMillis() - now; - if (LOG.isLoggable(INFO)) - LOG.info("Loading headers took " + duration + " ms"); + if (LOG.isLoggable(FINE)) + LOG.fine("Loading headers took " + (now() - start) + " ms"); // Load bodies into cache - now = System.currentTimeMillis(); + start = now(); for (H header : headers) { if (!bodyCache.containsKey(header.getId())) { bodyCache.put(header.getId(), loadMessageBody(header)); } } - duration = System.currentTimeMillis() - now; - if (LOG.isLoggable(INFO)) - LOG.info("Loading bodies took " + duration + " ms"); + if (LOG.isLoggable(FINE)) + LOG.fine("Loading bodies took " + (now() - start) + " ms"); // Build and hand over items handler.onResult(buildItems(headers)); @@ -197,13 +196,12 @@ public abstract class ThreadListControllerImpl<G extends NamedGroup, I extends T public void markItemsRead(Collection<I> items) { runOnDbThread(() -> { try { - long now = System.currentTimeMillis(); + long start = now(); for (I i : items) { markRead(i.getId()); } - long duration = System.currentTimeMillis() - now; - if (LOG.isLoggable(INFO)) - LOG.info("Marking read took " + duration + " ms"); + if (LOG.isLoggable(FINE)) + LOG.fine("Marking read took " + (now() - start) + " ms"); } catch (DbException e) { if (LOG.isLoggable(WARNING)) LOG.log(WARNING, e.toString(), e); } @@ -217,12 +215,11 @@ public abstract class ThreadListControllerImpl<G extends NamedGroup, I extends T ResultExceptionHandler<I, DbException> resultHandler) { runOnDbThread(() -> { try { - long now = System.currentTimeMillis(); + long start = now(); H header = addLocalMessage(msg); bodyCache.put(msg.getMessage().getId(), body); - long duration = System.currentTimeMillis() - now; - if (LOG.isLoggable(INFO)) - LOG.info("Storing message took " + duration + " ms"); + if (LOG.isLoggable(FINE)) + LOG.fine("Storing message took " + (now() - start) + " ms"); resultHandler.onResult(buildItem(header, body)); } catch (DbException e) { if (LOG.isLoggable(WARNING)) LOG.log(WARNING, e.toString(), e); @@ -238,12 +235,11 @@ public abstract class ThreadListControllerImpl<G extends NamedGroup, I extends T public void deleteNamedGroup(ExceptionHandler<DbException> handler) { runOnDbThread(() -> { try { - long now = System.currentTimeMillis(); + long start = now(); G groupItem = loadNamedGroup(); deleteNamedGroup(groupItem); - long duration = System.currentTimeMillis() - now; - if (LOG.isLoggable(INFO)) - LOG.info("Removing group took " + duration + " ms"); + if (LOG.isLoggable(FINE)) + LOG.fine("Removing group took " + (now() - start) + " ms"); } catch (DbException e) { if (LOG.isLoggable(WARNING)) LOG.log(WARNING, e.toString(), e); handler.onException(e);