From 703bc3a83056a878a83e263b992fb5331b84535f Mon Sep 17 00:00:00 2001 From: Jeff Sharkey Date: Mon, 25 Mar 2013 13:54:29 -0700 Subject: Reduce logging, dump stacks before wtf(). Most wtf() are looking like network timeouts, not threading bugs, so disable verbose debugging and add more targeted thread logging before calling wtf(). Bug: 8233041 Change-Id: I8e276bffd7880cfe13b65e7e81f5507cab627692 --- .../android/providers/downloads/DownloadInfo.java | 11 ++++++---- .../providers/downloads/DownloadNotifier.java | 25 +++++++++++++++++++++- .../providers/downloads/DownloadService.java | 14 +++++++++++- 3 files changed, 44 insertions(+), 6 deletions(-) diff --git a/src/com/android/providers/downloads/DownloadInfo.java b/src/com/android/providers/downloads/DownloadInfo.java index e6ed059b..7a912d5a 100644 --- a/src/com/android/providers/downloads/DownloadInfo.java +++ b/src/com/android/providers/downloads/DownloadInfo.java @@ -247,7 +247,10 @@ public class DownloadInfo { * {@link #startDownloadIfReady(ExecutorService)}. */ @GuardedBy("this") - private Future mActiveDownload; + private Future mSubmittedTask; + + @GuardedBy("this") + private DownloadThread mTask; private final Context mContext; private final SystemFacade mSystemFacade; @@ -455,7 +458,7 @@ public class DownloadInfo { public boolean startDownloadIfReady(ExecutorService executor) { synchronized (this) { final boolean isReady = isReadyToDownload(); - final boolean isActive = mActiveDownload != null && !mActiveDownload.isDone(); + final boolean isActive = mSubmittedTask != null && !mSubmittedTask.isDone(); if (isReady && !isActive) { if (mStatus != Impl.STATUS_RUNNING) { mStatus = Impl.STATUS_RUNNING; @@ -464,9 +467,9 @@ public class DownloadInfo { mContext.getContentResolver().update(getAllDownloadsUri(), values, null, null); } - final DownloadThread task = new DownloadThread( + mTask = new DownloadThread( mContext, mSystemFacade, this, mStorageManager, mNotifier); - mActiveDownload = executor.submit(task); + mSubmittedTask = executor.submit(mTask); } return isReady; } diff --git a/src/com/android/providers/downloads/DownloadNotifier.java b/src/com/android/providers/downloads/DownloadNotifier.java index 0af9cb86..f832eae3 100644 --- a/src/com/android/providers/downloads/DownloadNotifier.java +++ b/src/com/android/providers/downloads/DownloadNotifier.java @@ -20,6 +20,7 @@ import static android.app.DownloadManager.Request.VISIBILITY_VISIBLE; import static android.app.DownloadManager.Request.VISIBILITY_VISIBLE_NOTIFY_COMPLETED; import static android.app.DownloadManager.Request.VISIBILITY_VISIBLE_NOTIFY_ONLY_COMPLETION; import static android.provider.Downloads.Impl.STATUS_RUNNING; +import static com.android.providers.downloads.Constants.TAG; import android.app.DownloadManager; import android.app.Notification; @@ -30,9 +31,11 @@ import android.content.Context; import android.content.Intent; import android.content.res.Resources; import android.net.Uri; +import android.os.SystemClock; import android.provider.Downloads; import android.text.TextUtils; import android.text.format.DateUtils; +import android.util.Log; import android.util.LongSparseLongArray; import com.google.common.collect.ArrayListMultimap; @@ -75,6 +78,13 @@ public class DownloadNotifier { @GuardedBy("mDownloadSpeed") private final LongSparseLongArray mDownloadSpeed = new LongSparseLongArray(); + /** + * Last time speed was reproted, mapped from {@link DownloadInfo#mId} to + * {@link SystemClock#elapsedRealtime()}. + */ + @GuardedBy("mDownloadSpeed") + private final LongSparseLongArray mDownloadTouch = new LongSparseLongArray(); + public DownloadNotifier(Context context) { mContext = context; mNotifManager = (NotificationManager) context.getSystemService( @@ -86,15 +96,17 @@ public class DownloadNotifier { } /** - * Notify the current speed of an active download, used for calcuating + * Notify the current speed of an active download, used for calculating * estimated remaining time. */ public void notifyDownloadSpeed(long id, long bytesPerSecond) { synchronized (mDownloadSpeed) { if (bytesPerSecond != 0) { mDownloadSpeed.put(id, bytesPerSecond); + mDownloadTouch.put(id, SystemClock.elapsedRealtime()); } else { mDownloadSpeed.delete(id); + mDownloadTouch.delete(id); } } } @@ -302,6 +314,17 @@ public class DownloadNotifier { return ids; } + public void dumpSpeeds() { + synchronized (mDownloadSpeed) { + for (int i = 0; i < mDownloadSpeed.size(); i++) { + final long id = mDownloadSpeed.keyAt(i); + final long delta = SystemClock.elapsedRealtime() - mDownloadTouch.get(id); + Log.d(TAG, "Download " + id + " speed " + mDownloadSpeed.valueAt(i) + "bps, " + + delta + "ms ago"); + } + } + } + /** * Build tag used for collapsing several {@link DownloadInfo} into a single * {@link Notification}. diff --git a/src/com/android/providers/downloads/DownloadService.java b/src/com/android/providers/downloads/DownloadService.java index 07641097..6c61193c 100644 --- a/src/com/android/providers/downloads/DownloadService.java +++ b/src/com/android/providers/downloads/DownloadService.java @@ -49,6 +49,7 @@ import com.google.common.collect.Sets; import java.io.File; import java.io.FileDescriptor; import java.io.PrintWriter; +import java.util.Arrays; import java.util.Collections; import java.util.List; import java.util.Map; @@ -71,7 +72,7 @@ public class DownloadService extends Service { // TODO: migrate WakeLock from individual DownloadThreads out into // DownloadReceiver to protect our entire workflow. - private static final boolean DEBUG_LIFECYCLE = true; + private static final boolean DEBUG_LIFECYCLE = false; @VisibleForTesting SystemFacade mSystemFacade; @@ -237,6 +238,17 @@ public class DownloadService extends Service { } if (msg.what == MSG_FINAL_UPDATE) { + // Dump thread stacks belonging to pool + for (Map.Entry entry : + Thread.getAllStackTraces().entrySet()) { + if (entry.getKey().getName().startsWith("pool")) { + Log.d(TAG, entry.getKey() + ": " + Arrays.toString(entry.getValue())); + } + } + + // Dump speed and update details + mNotifier.dumpSpeeds(); + Log.wtf(TAG, "Final update pass triggered, isActive=" + isActive + "; someone didn't update correctly."); } -- cgit v1.2.3