From 9952f1c90ea6b150122cd5e79256c54419c7091e Mon Sep 17 00:00:00 2001 From: zachh Date: Thu, 22 Feb 2018 22:52:43 -0800 Subject: Added some logcat and metrics logging for new call log. Bug: 70989667 Test: unit PiperOrigin-RevId: 186726722 Change-Id: I1a68ae1e01b101b1624e4f5ede1a8d639d481ad2 --- .../calllog/RefreshAnnotatedCallLogWorker.java | 68 ++++++++++++++++------ .../calllog/database/CallLogDatabaseComponent.java | 2 - .../dialer/calllog/database/MutationApplier.java | 2 +- 3 files changed, 52 insertions(+), 20 deletions(-) (limited to 'java/com/android/dialer/calllog') diff --git a/java/com/android/dialer/calllog/RefreshAnnotatedCallLogWorker.java b/java/com/android/dialer/calllog/RefreshAnnotatedCallLogWorker.java index a430d14a8..3765831ae 100644 --- a/java/com/android/dialer/calllog/RefreshAnnotatedCallLogWorker.java +++ b/java/com/android/dialer/calllog/RefreshAnnotatedCallLogWorker.java @@ -19,7 +19,7 @@ package com.android.dialer.calllog; import android.content.Context; import android.content.SharedPreferences; import com.android.dialer.calllog.constants.SharedPrefKeys; -import com.android.dialer.calllog.database.CallLogDatabaseComponent; +import com.android.dialer.calllog.database.MutationApplier; import com.android.dialer.calllog.datasources.CallLogDataSource; import com.android.dialer.calllog.datasources.CallLogMutations; import com.android.dialer.calllog.datasources.DataSources; @@ -29,6 +29,9 @@ import com.android.dialer.common.concurrent.Annotations.LightweightExecutor; import com.android.dialer.common.concurrent.DialerFutureSerializer; import com.android.dialer.common.concurrent.DialerFutures; import com.android.dialer.inject.ApplicationContext; +import com.android.dialer.metrics.FutureTimer; +import com.android.dialer.metrics.FutureTimer.LogCatMode; +import com.android.dialer.metrics.Metrics; import com.android.dialer.storage.Unencrypted; import com.google.common.base.Preconditions; import com.google.common.util.concurrent.Futures; @@ -46,6 +49,8 @@ public class RefreshAnnotatedCallLogWorker { private final Context appContext; private final DataSources dataSources; private final SharedPreferences sharedPreferences; + private final MutationApplier mutationApplier; + private final FutureTimer futureTimer; private final ListeningExecutorService backgroundExecutorService; private final ListeningExecutorService lightweightExecutorService; // Used to ensure that only one refresh flow runs at a time. (Note that @@ -57,11 +62,15 @@ public class RefreshAnnotatedCallLogWorker { @ApplicationContext Context appContext, DataSources dataSources, @Unencrypted SharedPreferences sharedPreferences, + MutationApplier mutationApplier, + FutureTimer futureTimer, @BackgroundExecutor ListeningExecutorService backgroundExecutorService, @LightweightExecutor ListeningExecutorService lightweightExecutorService) { this.appContext = appContext; this.dataSources = dataSources; this.sharedPreferences = sharedPreferences; + this.mutationApplier = mutationApplier; + this.futureTimer = futureTimer; this.backgroundExecutorService = backgroundExecutorService; this.lightweightExecutorService = lightweightExecutorService; } @@ -79,11 +88,10 @@ public class RefreshAnnotatedCallLogWorker { private ListenableFuture refresh(boolean checkDirty) { LogUtil.i("RefreshAnnotatedCallLogWorker.refresh", "submitting serialized refresh request"); return dialerFutureSerializer.submitAsync( - () -> checkDirtyAndRebuildIfNecessary(appContext, checkDirty), lightweightExecutorService); + () -> checkDirtyAndRebuildIfNecessary(checkDirty), lightweightExecutorService); } - private ListenableFuture checkDirtyAndRebuildIfNecessary( - Context appContext, boolean checkDirty) { + private ListenableFuture checkDirtyAndRebuildIfNecessary(boolean checkDirty) { ListenableFuture forceRebuildFuture = backgroundExecutorService.submit( () -> { @@ -112,7 +120,7 @@ public class RefreshAnnotatedCallLogWorker { forceRebuild -> Preconditions.checkNotNull(forceRebuild) ? Futures.immediateFuture(true) - : isDirty(appContext), + : isDirty(), lightweightExecutorService); // After determining isDirty, conditionally call rebuild. @@ -123,26 +131,36 @@ public class RefreshAnnotatedCallLogWorker { "RefreshAnnotatedCallLogWorker.checkDirtyAndRebuildIfNecessary", "isDirty: %b", Preconditions.checkNotNull(isDirty)); - return isDirty ? rebuild(appContext) : Futures.immediateFuture(null); + return isDirty ? rebuild() : Futures.immediateFuture(null); }, lightweightExecutorService); } - private ListenableFuture isDirty(Context appContext) { + private ListenableFuture isDirty() { List> isDirtyFutures = new ArrayList<>(); for (CallLogDataSource dataSource : dataSources.getDataSourcesIncludingSystemCallLog()) { - isDirtyFutures.add(dataSource.isDirty(appContext)); + ListenableFuture dataSourceDirty = dataSource.isDirty(appContext); + isDirtyFutures.add(dataSourceDirty); + String eventName = + String.format(Metrics.IS_DIRTY_TEMPLATE, dataSource.getClass().getSimpleName()); + futureTimer.applyTiming(dataSourceDirty, eventName, LogCatMode.LOG_VALUES); } // Simultaneously invokes isDirty on all data sources, returning as soon as one returns true. - return DialerFutures.firstMatching(isDirtyFutures, Preconditions::checkNotNull, false); + ListenableFuture isDirtyFuture = + DialerFutures.firstMatching(isDirtyFutures, Preconditions::checkNotNull, false); + futureTimer.applyTiming(isDirtyFuture, Metrics.IS_DIRTY_EVENT_NAME, LogCatMode.LOG_VALUES); + return isDirtyFuture; } - private ListenableFuture rebuild(Context appContext) { + private ListenableFuture rebuild() { CallLogMutations mutations = new CallLogMutations(); // Start by filling the data sources--the system call log data source must go first! CallLogDataSource systemCallLogDataSource = dataSources.getSystemCallLogDataSource(); ListenableFuture fillFuture = systemCallLogDataSource.fill(appContext, mutations); + String systemEventName = + String.format(Metrics.FILL_TEMPLATE, systemCallLogDataSource.getClass().getSimpleName()); + futureTimer.applyTiming(fillFuture, systemEventName); // After the system call log data source is filled, call fill sequentially on each remaining // data source. This must be done sequentially because mutations are not threadsafe and are @@ -151,19 +169,28 @@ public class RefreshAnnotatedCallLogWorker { fillFuture = Futures.transformAsync( fillFuture, - unused -> dataSource.fill(appContext, mutations), + unused -> { + ListenableFuture dataSourceFuture = dataSource.fill(appContext, mutations); + String eventName = + String.format(Metrics.FILL_TEMPLATE, dataSource.getClass().getSimpleName()); + futureTimer.applyTiming(dataSourceFuture, eventName); + return dataSourceFuture; + }, lightweightExecutorService); } + futureTimer.applyTiming(fillFuture, Metrics.FILL_EVENT_NAME); // After all data sources are filled, apply mutations (at this point "fillFuture" is the result // of filling the last data source). ListenableFuture applyMutationsFuture = Futures.transformAsync( fillFuture, - unused -> - CallLogDatabaseComponent.get(appContext) - .mutationApplier() - .applyToDatabase(mutations, appContext), + unused -> { + ListenableFuture mutationApplierFuture = + mutationApplier.applyToDatabase(mutations, appContext); + futureTimer.applyTiming(mutationApplierFuture, Metrics.APPLY_MUTATIONS_EVENT_NAME); + return mutationApplierFuture; + }, lightweightExecutorService); // After mutations applied, call onSuccessfulFill for each data source (in parallel). @@ -174,9 +201,16 @@ public class RefreshAnnotatedCallLogWorker { List> onSuccessfulFillFutures = new ArrayList<>(); for (CallLogDataSource dataSource : dataSources.getDataSourcesIncludingSystemCallLog()) { - onSuccessfulFillFutures.add(dataSource.onSuccessfulFill(appContext)); + ListenableFuture dataSourceFuture = dataSource.onSuccessfulFill(appContext); + onSuccessfulFillFutures.add(dataSourceFuture); + String eventName = + String.format( + Metrics.ON_SUCCESSFUL_FILL_TEMPLATE, dataSource.getClass().getSimpleName()); + futureTimer.applyTiming(dataSourceFuture, eventName); } - return Futures.allAsList(onSuccessfulFillFutures); + ListenableFuture> allFutures = Futures.allAsList(onSuccessfulFillFutures); + futureTimer.applyTiming(allFutures, Metrics.ON_SUCCESSFUL_FILL_EVENT_NAME); + return allFutures; }, lightweightExecutorService); diff --git a/java/com/android/dialer/calllog/database/CallLogDatabaseComponent.java b/java/com/android/dialer/calllog/database/CallLogDatabaseComponent.java index ede46911c..991237449 100644 --- a/java/com/android/dialer/calllog/database/CallLogDatabaseComponent.java +++ b/java/com/android/dialer/calllog/database/CallLogDatabaseComponent.java @@ -25,8 +25,6 @@ public abstract class CallLogDatabaseComponent { public abstract Coalescer coalescer(); - public abstract MutationApplier mutationApplier(); - public static CallLogDatabaseComponent get(Context context) { return ((CallLogDatabaseComponent.HasComponent) ((HasRootComponent) context.getApplicationContext()).component()) diff --git a/java/com/android/dialer/calllog/database/MutationApplier.java b/java/com/android/dialer/calllog/database/MutationApplier.java index c9edd3ee1..86109343b 100644 --- a/java/com/android/dialer/calllog/database/MutationApplier.java +++ b/java/com/android/dialer/calllog/database/MutationApplier.java @@ -45,7 +45,7 @@ public class MutationApplier { private final ListeningExecutorService backgroundExecutorService; @Inject - MutationApplier(@BackgroundExecutor ListeningExecutorService backgroundExecutorService) { + public MutationApplier(@BackgroundExecutor ListeningExecutorService backgroundExecutorService) { this.backgroundExecutorService = backgroundExecutorService; } -- cgit v1.2.3