Replace boilerplate with static method.

bramble-api/src/main/java/org/briarproject/bramble/util/TimeUtils.java

@@ -1,5 +1,9 @@
 package org.briarproject.bramble.util;
 
+import java.util.logging.Logger;
+
+import static java.util.logging.Level.FINE;
+
 public class TimeUtils {
 
 	private static final int NANOS_PER_MILLI = 1000 * 1000;
@@ -11,4 +15,17 @@ public class TimeUtils {
 	public static long now() {
 		return System.nanoTime() / NANOS_PER_MILLI;
 	}
+
+	/**
+	 * Logs the duration of a task.
+	 * @param logger the logger to use
+	 * @param task a description of the task
+	 * @param start the start time of the task, as returned by {@link #now()}
+	 */
+	public static void logDuration(Logger logger, String task, long start) {
+		if (logger.isLoggable(FINE)) {
+			long duration = now() - start;
+			logger.fine(task + " took " + duration + " ms");
+		}
+	}
 }

bramble-core/src/main/java/org/briarproject/bramble/crypto/CryptoComponentImpl.java

@@ -30,9 +30,9 @@ 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.logDuration;
 import static org.briarproject.bramble.util.TimeUtils.now;
 
 @NotNullByDefault
@@ -136,8 +136,7 @@ class CryptoComponentImpl implements CryptoComponent {
 		byte allZero = 0;
 		for (byte b : secret) allZero |= b;
 		if (allZero == 0) throw new GeneralSecurityException();
-		if (LOG.isLoggable(FINE))
+		logDuration(LOG, "Deriving shared secret", start);
-			LOG.fine("Deriving shared secret took " + (now() - start) + " ms");
 		return secret;
 	}
 

bramble-core/src/main/java/org/briarproject/bramble/crypto/ScryptKdf.java

@@ -9,8 +9,8 @@ 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.logDuration;
 import static org.briarproject.bramble.util.TimeUtils.now;
 
 class ScryptKdf implements PasswordBasedKdf {
@@ -56,10 +56,7 @@ class ScryptKdf implements PasswordBasedKdf {
 		byte[] passwordBytes = StringUtils.toUtf8(password);
 		SecretKey k = new SecretKey(SCrypt.generate(passwordBytes, salt, cost,
 				BLOCK_SIZE, PARALLELIZATION, SecretKey.LENGTH));
-		if (LOG.isLoggable(FINE)) {
+		logDuration(LOG, "Deriving key from password", start);
-			long duration = now() - start;
-			LOG.fine("Deriving key from password took " + duration + " ms");
-		}
 		return k;
 	}
 }

bramble-core/src/main/java/org/briarproject/bramble/crypto/Sec1KeyParser.java

@@ -16,7 +16,7 @@ import java.util.logging.Logger;
 
 import javax.annotation.concurrent.Immutable;
 
-import static java.util.logging.Level.FINE;
+import static org.briarproject.bramble.util.TimeUtils.logDuration;
 import static org.briarproject.bramble.util.TimeUtils.now;
 
 /**
@@ -81,8 +81,7 @@ 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);
-		if (LOG.isLoggable(FINE))
+		logDuration(LOG, "Parsing public key", start);
-			LOG.fine("Parsing public key took " + (now() - start) + " ms");
 		return p;
 	}
 
@@ -99,8 +98,7 @@ 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);
-		if (LOG.isLoggable(FINE))
+		logDuration(LOG, "Parsing private key", start);
-			LOG.fine("Parsing private key took " + (now() - start) + " ms");
 		return p;
 	}
 }

bramble-core/src/main/java/org/briarproject/bramble/db/DatabaseComponentImpl.java

@@ -68,13 +68,13 @@ 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.WARNING;
 import static org.briarproject.bramble.api.sync.Group.Visibility.INVISIBLE;
 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.logDuration;
 import static org.briarproject.bramble.util.TimeUtils.now;
 
 @ThreadSafe
@@ -127,12 +127,12 @@ class DatabaseComponentImpl<T> implements DatabaseComponent {
 		if (lock.getReadHoldCount() > 0) throw new IllegalStateException();
 		if (lock.getWriteHoldCount() > 0) throw new IllegalStateException();
 		long start = now();
-		if (readOnly) lock.readLock().lock();
+		if (readOnly) {
-		else lock.writeLock().lock();
+			lock.readLock().lock();
-		if (LOG.isLoggable(FINE)) {
+			logDuration(LOG, "Waiting for read lock", start);
-			long duration = now() - start;
+		} else {
-			if (readOnly) LOG.fine("Waited " + duration + " ms for read lock");
+			lock.writeLock().lock();
-			else LOG.fine("Waited " + duration + " ms for write lock");
+			logDuration(LOG, "Waiting for write lock", start);
 		}
 		try {
 			return new Transaction(db.startTransaction(), readOnly);

bramble-core/src/main/java/org/briarproject/bramble/lifecycle/LifecycleManagerImpl.java

@@ -44,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.logDuration;
 import static org.briarproject.bramble.util.TimeUtils.now;
 
 @ThreadSafe
@@ -109,18 +110,14 @@ class LifecycleManagerImpl implements LifecycleManager, MigrationListener {
 		byte[] privateKey = keyPair.getPrivate().getEncoded();
 		LocalAuthor localAuthor = authorFactory
 				.createLocalAuthor(nickname, publicKey, privateKey);
-		if (LOG.isLoggable(FINE))
+		logDuration(LOG, "Creating local author", start);
-			LOG.fine("Creating local author took " + (now() - start) + " ms");
 		return localAuthor;
 	}
 
 	private void registerLocalAuthor(LocalAuthor author) throws DbException {
 		long start = now();
 		identityManager.registerLocalAuthor(author);
-		if (LOG.isLoggable(FINE)) {
+		logDuration(LOG, "Registering local author", start);
-			LOG.fine("Registering local author took " + (now() - start)
-					+ " ms");
-		}
 	}
 
 	@Override
@@ -134,12 +131,8 @@ class LifecycleManagerImpl implements LifecycleManager, MigrationListener {
 			long start = now();
 
 			boolean reopened = db.open(this);
-			if (LOG.isLoggable(FINE)) {
+			if (reopened) logDuration(LOG, "Reopening database", start);
-				long duration = now() - start;
+			else logDuration(LOG, "Creating database", start);
-				if (reopened)
-					LOG.fine("Reopening database took " + duration + " ms");
-				else LOG.fine("Creating database took " + duration + " ms");
-			}
 
 			if (nickname != null) {
 				registerLocalAuthor(createLocalAuthor(nickname));
@@ -155,9 +148,8 @@ class LifecycleManagerImpl implements LifecycleManager, MigrationListener {
 					start = now();
 					c.createLocalState(txn);
 					if (LOG.isLoggable(FINE)) {
-						LOG.fine("Starting client "
+						logDuration(LOG, "Starting client "
-								+ c.getClass().getSimpleName()
+								+ c.getClass().getSimpleName(), start);
-								+ " took " + (now() - start) + " ms");
 					}
 				}
 				db.commitTransaction(txn);
@@ -168,8 +160,8 @@ class LifecycleManagerImpl implements LifecycleManager, MigrationListener {
 				start = now();
 				s.startService();
 				if (LOG.isLoggable(FINE)) {
-					LOG.fine("Starting service " + s.getClass().getSimpleName()
+					logDuration(LOG, "Starting service "
-							+ " took " + (now() - start) + " ms");
+							+ s.getClass().getSimpleName(), start);
 				}
 			}
 
@@ -216,8 +208,8 @@ class LifecycleManagerImpl implements LifecycleManager, MigrationListener {
 				long start = now();
 				s.stopService();
 				if (LOG.isLoggable(FINE)) {
-					LOG.fine("Stopping service " + s.getClass().getSimpleName()
+					logDuration(LOG, "Stopping service "
-							+ " took " + (now() - start) + " ms");
+							+ s.getClass().getSimpleName(), start);
 				}
 			}
 			for (ExecutorService e : executors) {
@@ -229,8 +221,7 @@ class LifecycleManagerImpl implements LifecycleManager, MigrationListener {
 			}
 			long start = now();
 			db.close();
-			if (LOG.isLoggable(FINE))
+			logDuration(LOG, "Closing database", start);
-				LOG.fine("Closing database took " + (now() - start) + " ms");
 			shutdownLatch.countDown();
 		} catch (DbException | ServiceException e) {
 			if (LOG.isLoggable(WARNING)) LOG.log(WARNING, e.toString(), e);

bramble-core/src/main/java/org/briarproject/bramble/plugin/PluginManagerImpl.java

@@ -52,6 +52,7 @@ 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.logDuration;
 import static org.briarproject.bramble.util.TimeUtils.now;
 
 @ThreadSafe
@@ -210,8 +211,8 @@ class PluginManagerImpl implements PluginManager, Service {
 				long start = now();
 				plugin.start();
 				if (LOG.isLoggable(FINE)) {
-					LOG.fine("Starting plugin " + plugin.getId()
+					logDuration(LOG, "Starting plugin " + plugin.getId(),
-							+ " took " + (now() - start) + " ms");
+							start);
 				}
 			} catch (PluginException e) {
 				if (LOG.isLoggable(WARNING)) {
@@ -247,8 +248,8 @@ class PluginManagerImpl implements PluginManager, Service {
 				long start = now();
 				plugin.stop();
 				if (LOG.isLoggable(FINE)) {
-					LOG.fine("Stopping plugin " + plugin.getId()
+					logDuration(LOG, "Stopping plugin " + plugin.getId(),
-							+ " took " + (now() - start) + " ms");
+							start);
 				}
 			} catch (InterruptedException e) {
 				LOG.warning("Interrupted while waiting for plugin to stop");

briar-android/src/main/java/org/briarproject/briar/android/blog/BaseControllerImpl.java

@@ -32,8 +32,8 @@ import java.util.logging.Logger;
 
 import javax.annotation.Nullable;
 
-import static java.util.logging.Level.FINE;
 import static java.util.logging.Level.WARNING;
+import static org.briarproject.bramble.util.TimeUtils.logDuration;
 import static org.briarproject.bramble.util.TimeUtils.now;
 import static org.briarproject.briar.util.HtmlUtils.ARTICLE;
 
@@ -113,8 +113,7 @@ abstract class BaseControllerImpl extends DbControllerImpl
 		long start = now();
 		Collection<BlogPostHeader> headers =
 				blogManager.getPostHeaders(groupId);
-		if (LOG.isLoggable(FINE))
+		logDuration(LOG, "Loading headers", start);
-			LOG.fine("Loading headers took " + (now() - start) + " ms");
 		Collection<BlogPostItem> items = new ArrayList<>(headers.size());
 		start = now();
 		for (BlogPostHeader h : headers) {
@@ -122,8 +121,7 @@ abstract class BaseControllerImpl extends DbControllerImpl
 			BlogPostItem item = getItem(h);
 			items.add(item);
 		}
-		if (LOG.isLoggable(FINE))
+		logDuration(LOG, "Loading bodies", start);
-			LOG.fine("Loading bodies took " + (now() - start) + " ms");
 		return items;
 	}
 
@@ -141,8 +139,7 @@ abstract class BaseControllerImpl extends DbControllerImpl
 			try {
 				long start = now();
 				BlogPostItem item = getItem(header);
-				if (LOG.isLoggable(FINE))
+				logDuration(LOG, "Loading body", start);
-					LOG.fine("Loading body took " + (now() - start) + " ms");
 				handler.onResult(item);
 			} catch (DbException e) {
 				if (LOG.isLoggable(WARNING))
@@ -167,8 +164,7 @@ abstract class BaseControllerImpl extends DbControllerImpl
 				long start = now();
 				BlogPostHeader header1 = getPostHeader(g, m);
 				BlogPostItem item = getItem(header1);
-				if (LOG.isLoggable(FINE))
+				logDuration(LOG, "Loading post", start);
-					LOG.fine("Loading post took " + (now() - start) + " ms");
 				handler.onResult(item);
 			} catch (DbException e) {
 				if (LOG.isLoggable(WARNING))

briar-android/src/main/java/org/briarproject/briar/android/blog/BlogControllerImpl.java

@@ -35,8 +35,8 @@ import java.util.logging.Logger;
 
 import javax.inject.Inject;
 
-import static java.util.logging.Level.FINE;
 import static java.util.logging.Level.WARNING;
+import static org.briarproject.bramble.util.TimeUtils.logDuration;
 import static org.briarproject.bramble.util.TimeUtils.now;
 
 @MethodsNotNullByDefault
@@ -161,8 +161,7 @@ class BlogControllerImpl extends BaseControllerImpl
 				boolean ours = a.getId().equals(b.getAuthor().getId());
 				boolean removable = blogManager.canBeRemoved(b);
 				BlogItem blog = new BlogItem(b, ours, removable);
-				if (LOG.isLoggable(FINE))
+				logDuration(LOG, "Loading blog", start);
-					LOG.fine("Loading blog took " + (now() - start) + " ms");
 				handler.onResult(blog);
 			} catch (DbException e) {
 				if (LOG.isLoggable(WARNING))
@@ -180,8 +179,7 @@ class BlogControllerImpl extends BaseControllerImpl
 				long start = now();
 				Blog b = blogManager.getBlog(groupId);
 				blogManager.removeBlog(b);
-				if (LOG.isLoggable(FINE))
+				logDuration(LOG, "Removing blog", start);
-					LOG.fine("Removing blog took " + (now() - start) + " ms");
 				handler.onResult(null);
 			} catch (DbException e) {
 				if (LOG.isLoggable(WARNING))

briar-android/src/main/java/org/briarproject/briar/android/blog/FeedControllerImpl.java

@@ -26,8 +26,8 @@ import java.util.logging.Logger;
 
 import javax.inject.Inject;
 
-import static java.util.logging.Level.FINE;
 import static java.util.logging.Level.WARNING;
+import static org.briarproject.bramble.util.TimeUtils.logDuration;
 import static org.briarproject.bramble.util.TimeUtils.now;
 import static org.briarproject.briar.api.blog.BlogManager.CLIENT_ID;
 
@@ -110,10 +110,7 @@ class FeedControllerImpl extends BaseControllerImpl
 							LOG.log(WARNING, e.toString(), e);
 					}
 				}
-				if (LOG.isLoggable(FINE)) {
+				logDuration(LOG, "Loading all posts", start);
-					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);
@@ -130,9 +127,7 @@ class FeedControllerImpl extends BaseControllerImpl
 				long start = now();
 				Author a = identityManager.getLocalAuthor();
 				Blog b = blogManager.getPersonalBlog(a);
-				long duration = now() - start;
+				logDuration(LOG, "Loading personal blog", 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);

briar-android/src/main/java/org/briarproject/briar/android/contact/ContactListFragment.java

@@ -59,8 +59,8 @@ 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.FINE;
 import static java.util.logging.Level.WARNING;
+import static org.briarproject.bramble.util.TimeUtils.logDuration;
 import static org.briarproject.bramble.util.TimeUtils.now;
 import static org.briarproject.briar.android.contact.ConversationActivity.CONTACT_ID;
 
@@ -209,8 +209,7 @@ public class ContactListFragment extends BaseFragment implements EventListener {
 						// Continue
 					}
 				}
-				if (LOG.isLoggable(FINE))
+				logDuration(LOG, "Full load", start);
-					LOG.fine("Full load took " + (now() - start) + " ms");
 				displayContacts(revision, contacts);
 			} catch (DbException e) {
 				if (LOG.isLoggable(WARNING)) LOG.log(WARNING, e.toString(), e);

briar-android/src/main/java/org/briarproject/briar/android/contact/ConversationActivity.java

@@ -104,9 +104,9 @@ 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.logDuration;
 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;
@@ -298,8 +298,7 @@ public class ConversationActivity extends BriarActivity
 					contactName = contact.getAuthor().getName();
 					contactAuthorId = contact.getAuthor().getId();
 				}
-				if (LOG.isLoggable(FINE))
+				logDuration(LOG, "Loading contact", start);
-					LOG.fine("Loading contact took " + (now() - start) + " ms");
 				loadMessages();
 				displayContactDetails();
 			} catch (NoSuchContactException e) {
@@ -358,10 +357,7 @@ public class ConversationActivity extends BriarActivity
 				invitations.addAll(forumInvitations);
 				invitations.addAll(blogInvitations);
 				invitations.addAll(groupInvitations);
-				if (LOG.isLoggable(FINE)) {
+				logDuration(LOG, "Loading messages", start);
-					long duration = now() - start;
-					LOG.fine("Loading messages took " + duration + " ms");
-				}
 				displayMessages(revision, headers, introductions, invitations);
 			} catch (NoSuchContactException e) {
 				finishOnUiThread();
@@ -442,8 +438,7 @@ public class ConversationActivity extends BriarActivity
 			try {
 				long start = now();
 				String body = messagingManager.getMessageBody(m);
-				if (LOG.isLoggable(FINE))
+				logDuration(LOG, "Loading body", start);
-					LOG.fine("Loading body took " + (now() - start) + " ms");
 				displayMessageBody(m, body);
 			} catch (DbException e) {
 				if (LOG.isLoggable(WARNING)) LOG.log(WARNING, e.toString(), e);
@@ -692,8 +687,7 @@ public class ConversationActivity extends BriarActivity
 			try {
 				long start = now();
 				messagingManager.addLocalMessage(m);
-				if (LOG.isLoggable(FINE))
+				logDuration(LOG, "Storing message", start);
-					LOG.fine("Storing message took " + (now() - start) + " ms");
 				Message message = m.getMessage();
 				PrivateMessageHeader h = new PrivateMessageHeader(
 						message.getId(), message.getGroupId(),
@@ -818,8 +812,7 @@ public class ConversationActivity extends BriarActivity
 			try {
 				long start = now();
 				messagingManager.setReadFlag(g, m, true);
-				if (LOG.isLoggable(FINE))
+				logDuration(LOG, "Marking read", start);
-					LOG.fine("Marking read took " + (now() - start) + " ms");
 			} catch (DbException e) {
 				if (LOG.isLoggable(WARNING)) LOG.log(WARNING, e.toString(), e);
 			}

briar-android/src/main/java/org/briarproject/briar/android/forum/CreateForumActivity.java

@@ -28,8 +28,8 @@ 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.FINE;
 import static java.util.logging.Level.WARNING;
+import static org.briarproject.bramble.util.TimeUtils.logDuration;
 import static org.briarproject.bramble.util.TimeUtils.now;
 import static org.briarproject.briar.api.forum.ForumConstants.MAX_FORUM_NAME_LENGTH;
 
@@ -125,8 +125,7 @@ public class CreateForumActivity extends BriarActivity {
 			try {
 				long start = now();
 				Forum f = forumManager.addForum(name);
-				if (LOG.isLoggable(FINE))
+				logDuration(LOG, "Storing forum", start);
-					LOG.fine("Storing forum took " + (now() - start) + " ms");
 				displayForum(f);
 			} catch (DbException e) {
 				if (LOG.isLoggable(WARNING)) LOG.log(WARNING, e.toString(), e);

briar-android/src/main/java/org/briarproject/briar/android/forum/ForumListFragment.java

@@ -44,8 +44,8 @@ import javax.annotation.Nullable;
 import javax.inject.Inject;
 
 import static android.support.design.widget.Snackbar.LENGTH_INDEFINITE;
-import static java.util.logging.Level.FINE;
 import static java.util.logging.Level.WARNING;
+import static org.briarproject.bramble.util.TimeUtils.logDuration;
 import static org.briarproject.bramble.util.TimeUtils.now;
 import static org.briarproject.briar.api.forum.ForumManager.CLIENT_ID;
 
@@ -169,8 +169,7 @@ public class ForumListFragment extends BaseEventFragment implements
 						// Continue
 					}
 				}
-				if (LOG.isLoggable(FINE))
+				logDuration(LOG, "Full load", start);
-					LOG.fine("Full load took " + (now() - start) + " ms");
 				displayForums(revision, forums);
 			} catch (DbException e) {
 				if (LOG.isLoggable(WARNING)) LOG.log(WARNING, e.toString(), e);
@@ -196,10 +195,7 @@ public class ForumListFragment extends BaseEventFragment implements
 			try {
 				long start = now();
 				int available = forumSharingManager.getInvitations().size();
-				if (LOG.isLoggable(FINE)) {
+				logDuration(LOG, "Loading available", start);
-					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);

briar-android/src/main/java/org/briarproject/briar/android/login/PasswordControllerImpl.java

@@ -17,7 +17,7 @@ import java.util.logging.Logger;
 
 import javax.inject.Inject;
 
-import static java.util.logging.Level.FINE;
+import static org.briarproject.bramble.util.TimeUtils.logDuration;
 import static org.briarproject.bramble.util.TimeUtils.now;
 
 @NotNullByDefault
@@ -89,8 +89,7 @@ public class PasswordControllerImpl extends ConfigControllerImpl
 	String encryptDatabaseKey(SecretKey key, String password) {
 		long start = now();
 		byte[] encrypted = crypto.encryptWithPassword(key.getBytes(), password);
-		if (LOG.isLoggable(FINE))
+		logDuration(LOG, "Key derivation", start);
-			LOG.fine("Key derivation took " + (now() - start) + " ms");
 		return StringUtils.toHexString(encrypted);
 	}
 }

briar-android/src/main/java/org/briarproject/briar/android/privategroup/list/GroupListControllerImpl.java

@@ -36,8 +36,8 @@ import java.util.logging.Logger;
 
 import javax.inject.Inject;
 
-import static java.util.logging.Level.FINE;
 import static java.util.logging.Level.WARNING;
+import static org.briarproject.bramble.util.TimeUtils.logDuration;
 import static org.briarproject.bramble.util.TimeUtils.now;
 import static org.briarproject.briar.api.privategroup.PrivateGroupManager.CLIENT_ID;
 
@@ -162,8 +162,7 @@ class GroupListControllerImpl extends DbControllerImpl
 						// Continue
 					}
 				}
-				if (LOG.isLoggable(FINE))
+				logDuration(LOG, "Loading groups", start);
-					LOG.fine("Loading groups took " + (now() - start) + " ms");
 				handler.onResult(items);
 			} catch (DbException e) {
 				if (LOG.isLoggable(WARNING)) LOG.log(WARNING, e.toString(), e);
@@ -178,8 +177,7 @@ class GroupListControllerImpl extends DbControllerImpl
 			try {
 				long start = now();
 				groupManager.removePrivateGroup(g);
-				if (LOG.isLoggable(FINE))
+				logDuration(LOG, "Removing group", start);
-					LOG.fine("Removing group took " + (now() - start) + " ms");
 			} catch (DbException e) {
 				if (LOG.isLoggable(WARNING)) LOG.log(WARNING, e.toString(), e);
 				handler.onException(e);

briar-android/src/main/java/org/briarproject/briar/android/settings/SettingsFragment.java

@@ -59,12 +59,12 @@ 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.logDuration;
 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;
@@ -249,10 +249,7 @@ public class SettingsFragment extends PreferenceFragmentCompat
 				Settings btSettings = settingsManager.getSettings(BT_NAMESPACE);
 				Settings torSettings =
 						settingsManager.getSettings(TOR_NAMESPACE);
-				if (LOG.isLoggable(FINE)) {
+				logDuration(LOG, "Loading settings", start);
-					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,
@@ -440,10 +437,7 @@ public class SettingsFragment extends PreferenceFragmentCompat
 				s.putInt(PREF_TOR_NETWORK, torSetting);
 				long start = now();
 				settingsManager.mergeSettings(s, TOR_NAMESPACE);
-				if (LOG.isLoggable(FINE)) {
+				logDuration(LOG, "Merging settings", start);
-					long duration = now() - start;
-					LOG.fine("Merging settings took " + duration + " ms");
-				}
 			} catch (DbException e) {
 				if (LOG.isLoggable(WARNING)) LOG.log(WARNING, e.toString(), e);
 			}
@@ -457,10 +451,7 @@ public class SettingsFragment extends PreferenceFragmentCompat
 				s.putBoolean(PREF_BT_ENABLE, btSetting);
 				long start = now();
 				settingsManager.mergeSettings(s, BT_NAMESPACE);
-				if (LOG.isLoggable(FINE)) {
+				logDuration(LOG, "Merging settings", start);
-					long duration = now() - start;
-					LOG.fine("Merging settings took " + duration + " ms");
-				}
 			} catch (DbException e) {
 				if (LOG.isLoggable(WARNING)) LOG.log(WARNING, e.toString(), e);
 			}
@@ -472,10 +463,7 @@ public class SettingsFragment extends PreferenceFragmentCompat
 			try {
 				long start = now();
 				settingsManager.mergeSettings(settings, SETTINGS_NAMESPACE);
-				if (LOG.isLoggable(FINE)) {
+				logDuration(LOG, "Merging settings", start);
-					long duration = now() - start;
-					LOG.fine("Merging settings took " + duration + " ms");
-				}
 			} catch (DbException e) {
 				if (LOG.isLoggable(WARNING)) LOG.log(WARNING, e.toString(), e);
 			}

briar-android/src/main/java/org/briarproject/briar/android/sharing/InvitationControllerImpl.java

@@ -24,8 +24,8 @@ import java.util.Collection;
 import java.util.concurrent.Executor;
 import java.util.logging.Logger;
 
-import static java.util.logging.Level.FINE;
 import static java.util.logging.Level.WARNING;
+import static org.briarproject.bramble.util.TimeUtils.logDuration;
 import static org.briarproject.bramble.util.TimeUtils.now;
 
 @MethodsNotNullByDefault
@@ -98,10 +98,7 @@ public abstract class InvitationControllerImpl<I extends InvitationItem>
 			try {
 				long start = now();
 				Collection<I> invitations = new ArrayList<>(getInvitations());
-				if (LOG.isLoggable(FINE)) {
+				logDuration(LOG, "Loading invitations", start);
-					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);

briar-android/src/main/java/org/briarproject/briar/android/threaded/ThreadListControllerImpl.java

@@ -34,9 +34,9 @@ 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.logDuration;
 import static org.briarproject.bramble.util.TimeUtils.now;
 
 @MethodsNotNullByDefault
@@ -135,8 +135,7 @@ public abstract class ThreadListControllerImpl<G extends NamedGroup, I extends T
 			try {
 				long start = now();
 				G groupItem = loadNamedGroup();
-				if (LOG.isLoggable(FINE))
+				logDuration(LOG, "Loading group", start);
-					LOG.fine("Loading group took " + (now() - start) + " ms");
 				handler.onResult(groupItem);
 			} catch (DbException e) {
 				if (LOG.isLoggable(WARNING))
@@ -158,8 +157,7 @@ public abstract class ThreadListControllerImpl<G extends NamedGroup, I extends T
 				// Load headers
 				long start = now();
 				Collection<H> headers = loadHeaders();
-				if (LOG.isLoggable(FINE))
+				logDuration(LOG, "Loading headers", start);
-					LOG.fine("Loading headers took " + (now() - start) + " ms");
 
 				// Load bodies into cache
 				start = now();
@@ -169,8 +167,7 @@ public abstract class ThreadListControllerImpl<G extends NamedGroup, I extends T
 								loadMessageBody(header));
 					}
 				}
-				if (LOG.isLoggable(FINE))
+				logDuration(LOG, "Loading bodies", start);
-					LOG.fine("Loading bodies took " + (now() - start) + " ms");
 
 				// Build and hand over items
 				handler.onResult(buildItems(headers));
@@ -200,8 +197,7 @@ public abstract class ThreadListControllerImpl<G extends NamedGroup, I extends T
 				for (I i : items) {
 					markRead(i.getId());
 				}
-				if (LOG.isLoggable(FINE))
+				logDuration(LOG, "Marking read", start);
-					LOG.fine("Marking read took " + (now() - start) + " ms");
 			} catch (DbException e) {
 				if (LOG.isLoggable(WARNING)) LOG.log(WARNING, e.toString(), e);
 			}
@@ -218,8 +214,7 @@ public abstract class ThreadListControllerImpl<G extends NamedGroup, I extends T
 				long start = now();
 				H header = addLocalMessage(msg);
 				bodyCache.put(msg.getMessage().getId(), body);
-				if (LOG.isLoggable(FINE))
+				logDuration(LOG, "Storing message", start);
-					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,8 +233,7 @@ public abstract class ThreadListControllerImpl<G extends NamedGroup, I extends T
 				long start = now();
 				G groupItem = loadNamedGroup();
 				deleteNamedGroup(groupItem);
-				if (LOG.isLoggable(FINE))
+				logDuration(LOG, "Removing group", start);
-					LOG.fine("Removing group took " + (now() - start) + " ms");
 			} catch (DbException e) {
 				if (LOG.isLoggable(WARNING)) LOG.log(WARNING, e.toString(), e);
 				handler.onException(e);