Use SystemClock.elapsedRealtime() to measure durations

This commit is contained in:
Vatsal Sura 2017-03-13 23:42:37 +05:30
parent ea7af81382
commit ede2b0fb17
6 changed files with 46 additions and 41 deletions

View file

@ -4,13 +4,14 @@ import java.util.Timer;
import java.util.TimerTask; import java.util.TimerTask;
import java.util.concurrent.atomic.AtomicInteger; import java.util.concurrent.atomic.AtomicInteger;
import com.fsck.k9.mail.K9MailLib;
import android.content.Context; import android.content.Context;
import android.os.PowerManager; import android.os.PowerManager;
import android.os.PowerManager.WakeLock; import android.os.PowerManager.WakeLock;
import android.os.SystemClock;
import android.util.Log; import android.util.Log;
import com.fsck.k9.mail.K9MailLib;
import static com.fsck.k9.mail.K9MailLib.LOG_TAG; import static com.fsck.k9.mail.K9MailLib.LOG_TAG;
@ -67,7 +68,7 @@ public class TracingPowerManager {
} }
raiseNotification(); raiseNotification();
if (startTime == null) { if (startTime == null) {
startTime = System.currentTimeMillis(); startTime = SystemClock.elapsedRealtime();
} }
this.timeout = timeout; this.timeout = timeout;
} }
@ -80,7 +81,7 @@ public class TracingPowerManager {
Log.w(LOG_TAG, "TracingWakeLock for tag " + tag + " / id " + id + ": acquired with no timeout. K-9 Mail should not do this"); Log.w(LOG_TAG, "TracingWakeLock for tag " + tag + " / id " + id + ": acquired with no timeout. K-9 Mail should not do this");
} }
if (startTime == null) { if (startTime == null) {
startTime = System.currentTimeMillis(); startTime = SystemClock.elapsedRealtime();
} }
timeout = null; timeout = null;
} }
@ -91,7 +92,7 @@ public class TracingPowerManager {
} }
public void release() { public void release() {
if (startTime != null) { if (startTime != null) {
Long endTime = System.currentTimeMillis(); Long endTime = SystemClock.elapsedRealtime();
if (K9MailLib.isDebug()) { if (K9MailLib.isDebug()) {
Log.v(LOG_TAG, "TracingWakeLock for tag " + tag + " / id " + id + ": releasing after " + (endTime - startTime) + " ms, timeout = " + timeout + " ms"); Log.v(LOG_TAG, "TracingWakeLock for tag " + tag + " / id " + id + ": releasing after " + (endTime - startTime) + " ms, timeout = " + timeout + " ms");
} }
@ -126,7 +127,7 @@ public class TracingPowerManager {
@Override @Override
public void run() { public void run() {
if (startTime != null) { if (startTime != null) {
Long endTime = System.currentTimeMillis(); Long endTime = SystemClock.elapsedRealtime();
Log.i(LOG_TAG, "TracingWakeLock for tag " + tag + " / id " + id + ": has been active for " Log.i(LOG_TAG, "TracingWakeLock for tag " + tag + " / id " + id + ": has been active for "
+ (endTime - startTime) + " ms, timeout = " + timeout + " ms"); + (endTime - startTime) + " ms, timeout = " + timeout + " ms");

View file

@ -3,14 +3,14 @@ package com.fsck.k9.mailstore.migrations;
import java.util.List; import java.util.List;
import timber.log.Timber; import android.os.SystemClock;
import com.fsck.k9.K9;
import com.fsck.k9.mail.Folder; import com.fsck.k9.mail.Folder;
import com.fsck.k9.mailstore.LocalFolder; import com.fsck.k9.mailstore.LocalFolder;
import com.fsck.k9.mailstore.LocalStore; import com.fsck.k9.mailstore.LocalStore;
import com.fsck.k9.preferences.Storage; import com.fsck.k9.preferences.Storage;
import com.fsck.k9.preferences.StorageEditor; import com.fsck.k9.preferences.StorageEditor;
import timber.log.Timber;
class MigrationTo42 { class MigrationTo42 {
@ -19,7 +19,7 @@ class MigrationTo42 {
LocalStore localStore = migrationsHelper.getLocalStore(); LocalStore localStore = migrationsHelper.getLocalStore();
Storage storage = migrationsHelper.getStorage(); Storage storage = migrationsHelper.getStorage();
long startTime = System.currentTimeMillis(); long startTime = SystemClock.elapsedRealtime();
StorageEditor editor = storage.edit(); StorageEditor editor = storage.edit();
List<? extends Folder > folders = localStore.getPersonalNamespaces(true); List<? extends Folder > folders = localStore.getPersonalNamespaces(true);
@ -31,7 +31,7 @@ class MigrationTo42 {
} }
editor.commit(); editor.commit();
long endTime = System.currentTimeMillis(); long endTime = SystemClock.elapsedRealtime();
Timber.i("Putting folder preferences for %d folders back into Preferences took %d ms", Timber.i("Putting folder preferences for %d folders back into Preferences took %d ms",
folders.size(), endTime - startTime); folders.size(), endTime - startTime);
} catch (Exception e) { } catch (Exception e) {

View file

@ -1,16 +1,5 @@
package com.fsck.k9.preferences; package com.fsck.k9.preferences;
import android.content.ContentValues;
import android.content.Context;
import android.database.Cursor;
import android.database.sqlite.SQLiteDatabase;
import android.database.sqlite.SQLiteStatement;
import timber.log.Timber;
import com.fsck.k9.K9;
import com.fsck.k9.helper.UrlEncodingHelper;
import com.fsck.k9.helper.Utility;
import com.fsck.k9.mail.filter.Base64;
import java.net.URI; import java.net.URI;
import java.util.ArrayList; import java.util.ArrayList;
@ -19,6 +8,18 @@ import java.util.Map;
import java.util.concurrent.ConcurrentHashMap; import java.util.concurrent.ConcurrentHashMap;
import java.util.concurrent.ConcurrentMap; import java.util.concurrent.ConcurrentMap;
import android.content.ContentValues;
import android.content.Context;
import android.database.Cursor;
import android.database.sqlite.SQLiteDatabase;
import android.database.sqlite.SQLiteStatement;
import android.os.SystemClock;
import com.fsck.k9.helper.UrlEncodingHelper;
import com.fsck.k9.helper.Utility;
import com.fsck.k9.mail.filter.Base64;
import timber.log.Timber;
public class Storage { public class Storage {
private static ConcurrentMap<Context, Storage> storages = private static ConcurrentMap<Context, Storage> storages =
new ConcurrentHashMap<Context, Storage>(); new ConcurrentHashMap<Context, Storage>();
@ -158,7 +159,7 @@ public class Storage {
} }
private void loadValues() { private void loadValues() {
long startTime = System.currentTimeMillis(); long startTime = SystemClock.elapsedRealtime();
Timber.i("Loading preferences from DB into Storage"); Timber.i("Loading preferences from DB into Storage");
Cursor cursor = null; Cursor cursor = null;
SQLiteDatabase mDb = null; SQLiteDatabase mDb = null;
@ -177,7 +178,7 @@ public class Storage {
if (mDb != null) { if (mDb != null) {
mDb.close(); mDb.close();
} }
long endTime = System.currentTimeMillis(); long endTime = SystemClock.elapsedRealtime();
Timber.i("Preferences load took %d ms", endTime - startTime); Timber.i("Preferences load took %d ms", endTime - startTime);
} }
} }

View file

@ -1,7 +1,5 @@
package com.fsck.k9.preferences; package com.fsck.k9.preferences;
import timber.log.Timber;
import com.fsck.k9.K9;
import java.util.ArrayList; import java.util.ArrayList;
import java.util.HashMap; import java.util.HashMap;
@ -9,6 +7,10 @@ import java.util.List;
import java.util.Map; import java.util.Map;
import java.util.Map.Entry; import java.util.Map.Entry;
import android.os.SystemClock;
import timber.log.Timber;
public class StorageEditor { public class StorageEditor {
private Storage storage; private Storage storage;
@ -48,7 +50,7 @@ public class StorageEditor {
} }
private void commitChanges() { private void commitChanges() {
long startTime = System.currentTimeMillis(); long startTime = SystemClock.elapsedRealtime();
Timber.i("Committing preference changes"); Timber.i("Committing preference changes");
Runnable committer = new Runnable() { Runnable committer = new Runnable() {
public void run() { public void run() {
@ -68,7 +70,7 @@ public class StorageEditor {
} }
}; };
storage.doInTransaction(committer); storage.doInTransaction(committer);
long endTime = System.currentTimeMillis(); long endTime = SystemClock.elapsedRealtime();
Timber.i("Preferences commit took %d ms", endTime - startTime); Timber.i("Preferences commit took %d ms", endTime - startTime);
} }

View file

@ -1,26 +1,25 @@
package com.fsck.k9.service; package com.fsck.k9.service;
import java.util.Collection; import java.util.Collection;
import java.util.Date;
import android.content.ContentResolver; import android.content.ContentResolver;
import android.content.Context; import android.content.Context;
import android.content.Intent; import android.content.Intent;
import android.os.IBinder; import android.os.IBinder;
import timber.log.Timber; import android.os.SystemClock;
import com.fsck.k9.Account; import com.fsck.k9.Account;
import com.fsck.k9.Account.FolderMode;
import com.fsck.k9.K9; import com.fsck.k9.K9;
import com.fsck.k9.Preferences; import com.fsck.k9.Preferences;
import com.fsck.k9.Account.FolderMode;
import com.fsck.k9.controller.MessagingController; import com.fsck.k9.controller.MessagingController;
import com.fsck.k9.helper.Utility; import com.fsck.k9.helper.Utility;
import com.fsck.k9.mail.Pusher; import com.fsck.k9.mail.Pusher;
import com.fsck.k9.preferences.Storage; import com.fsck.k9.preferences.Storage;
import com.fsck.k9.preferences.StorageEditor; import com.fsck.k9.preferences.StorageEditor;
import timber.log.Timber;
import static java.lang.System.currentTimeMillis;
public class MailService extends CoreService { public class MailService extends CoreService {
@ -88,7 +87,7 @@ public class MailService extends CoreService {
@Override @Override
public int startService(Intent intent, int startId) { public int startService(Intent intent, int startId) {
long startTime = System.currentTimeMillis(); long startTime = SystemClock.elapsedRealtime();
boolean oldIsSyncDisabled = isSyncDisabled(); boolean oldIsSyncDisabled = isSyncDisabled();
boolean doBackground = true; boolean doBackground = true;
@ -149,7 +148,7 @@ public class MailService extends CoreService {
MessagingController.getInstance(getApplication()).systemStatusChanged(); MessagingController.getInstance(getApplication()).systemStatusChanged();
} }
Timber.i("MailService.onStart took %d ms", currentTimeMillis() - startTime); Timber.i("MailService.onStart took %d ms", SystemClock.elapsedRealtime() - startTime);
return START_NOT_STICKY; return START_NOT_STICKY;
} }

View file

@ -1,16 +1,18 @@
package com.fsck.k9.service; package com.fsck.k9.service;
import android.content.Context;
import android.content.Intent;
import timber.log.Timber;
import com.fsck.k9.K9;
import com.fsck.k9.mail.power.TracingPowerManager.TracingWakeLock;
import java.util.concurrent.ConcurrentHashMap; import java.util.concurrent.ConcurrentHashMap;
import java.util.concurrent.CountDownLatch; import java.util.concurrent.CountDownLatch;
import java.util.concurrent.TimeUnit; import java.util.concurrent.TimeUnit;
import java.util.concurrent.atomic.AtomicInteger; import java.util.concurrent.atomic.AtomicInteger;
import android.content.Context;
import android.content.Intent;
import android.os.SystemClock;
import com.fsck.k9.mail.power.TracingPowerManager.TracingWakeLock;
import timber.log.Timber;
import static java.lang.Thread.currentThread; import static java.lang.Thread.currentThread;
@ -37,7 +39,7 @@ public class SleepService extends CoreService {
Intent i = new Intent(context, SleepService.class); Intent i = new Intent(context, SleepService.class);
i.putExtra(LATCH_ID, id); i.putExtra(LATCH_ID, id);
i.setAction(ALARM_FIRED + "." + id); i.setAction(ALARM_FIRED + "." + id);
long startTime = System.currentTimeMillis(); long startTime = SystemClock.elapsedRealtime();
long nextTime = startTime + sleepTime; long nextTime = startTime + sleepTime;
BootReceiver.scheduleIntent(context, nextTime, i); BootReceiver.scheduleIntent(context, nextTime, i);
if (wakeLock != null) { if (wakeLock != null) {
@ -73,7 +75,7 @@ public class SleepService extends CoreService {
reacquireWakeLock(releaseDatum); reacquireWakeLock(releaseDatum);
} }
long endTime = System.currentTimeMillis(); long endTime = SystemClock.elapsedRealtime();
long actualSleep = endTime - startTime; long actualSleep = endTime - startTime;
if (actualSleep < sleepTime) { if (actualSleep < sleepTime) {