Merge branch 'fine-logging' into 'master'

Move logging of time measurements to FINE level

See merge request akwizgran/briar!836
This commit is contained in:
Torsten Grote
2018-06-15 15:00:25 +00:00
24 changed files with 235 additions and 222 deletions

View File

@@ -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");

View File

@@ -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;

View File

@@ -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))

View File

@@ -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))

View File

@@ -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);

View File

@@ -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

View File

@@ -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);

View File

@@ -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);
}

View File

@@ -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);

View File

@@ -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);

View File

@@ -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);
}
}

View File

@@ -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);

View File

@@ -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);
}

View File

@@ -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);

View File

@@ -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);