From 50c8f42568145b87b489e1ab65838f5fc434e5e6 Mon Sep 17 00:00:00 2001 From: Chris Wren Date: Wed, 15 Jan 2014 16:10:39 -0500 Subject: rationalize launcher backup logging enough data to debug dogfood issues easy switch to move to quieter production mode common switch across all three classes Bug: 12545310 Change-Id: Icb4ad7174f20884c6993140149db590d66f6e006 --- .../launcher3/LauncherBackupAgentHelper.java | 5 +- .../android/launcher3/LauncherBackupHelper.java | 91 ++++++++++++---------- .../launcher3/LauncherPreferencesBackupHelper.java | 5 ++ 3 files changed, 58 insertions(+), 43 deletions(-) (limited to 'src') diff --git a/src/com/android/launcher3/LauncherBackupAgentHelper.java b/src/com/android/launcher3/LauncherBackupAgentHelper.java index 876cf0887..de6aedddd 100644 --- a/src/com/android/launcher3/LauncherBackupAgentHelper.java +++ b/src/com/android/launcher3/LauncherBackupAgentHelper.java @@ -22,10 +22,13 @@ import android.app.backup.SharedPreferencesBackupHelper; import android.content.Context; import android.content.SharedPreferences; import android.provider.Settings; +import android.util.Log; public class LauncherBackupAgentHelper extends BackupAgentHelper { private static final String TAG = "LauncherBackupAgentHelper"; + static final boolean VERBOSE = true; + static final boolean DEBUG = false; private static BackupManager sBackupManager; @@ -57,9 +60,9 @@ public class LauncherBackupAgentHelper extends BackupAgentHelper { @Override public void onCreate() { - boolean restoreEnabled = 0 != Settings.Secure.getInt( getContentResolver(), SETTING_RESTORE_ENABLED, 0); + if (VERBOSE) Log.v(TAG, "restore is " + (restoreEnabled ? "enabled" : "disabled")); addHelper(LauncherBackupHelper.LAUNCHER_PREFS_PREFIX, new LauncherPreferencesBackupHelper(this, diff --git a/src/com/android/launcher3/LauncherBackupHelper.java b/src/com/android/launcher3/LauncherBackupHelper.java index 69b0026ed..57cdfb94a 100644 --- a/src/com/android/launcher3/LauncherBackupHelper.java +++ b/src/com/android/launcher3/LauncherBackupHelper.java @@ -13,7 +13,6 @@ * See the License for the specific language governing permissions and * limitations under the License. */ - package com.android.launcher3; import com.google.protobuf.nano.InvalidProtocolBufferNanoException; @@ -68,7 +67,8 @@ import java.util.zip.CRC32; public class LauncherBackupHelper implements BackupHelper { private static final String TAG = "LauncherBackupHelper"; - private static final boolean DEBUG = false; + private static final boolean VERBOSE = LauncherBackupAgentHelper.VERBOSE; + private static final boolean DEBUG = LauncherBackupAgentHelper.DEBUG; private static final boolean DEBUG_PAYLOAD = false; private static final int MAX_JOURNAL_SIZE = 1000000; @@ -171,7 +171,7 @@ public class LauncherBackupHelper implements BackupHelper { @Override public void performBackup(ParcelFileDescriptor oldState, BackupDataOutput data, ParcelFileDescriptor newState) { - Log.v(TAG, "onBackup"); + if (VERBOSE) Log.v(TAG, "onBackup"); Journal in = readJournal(oldState); Journal out = new Journal(); @@ -181,7 +181,7 @@ public class LauncherBackupHelper implements BackupHelper { out.rows = 0; out.bytes = 0; - Log.v(TAG, "lastBackupTime=" + lastBackupTime); + Log.v(TAG, "lastBackupTime = " + lastBackupTime); ArrayList keys = new ArrayList(); try { @@ -207,7 +207,7 @@ public class LauncherBackupHelper implements BackupHelper { */ @Override public void restoreEntity(BackupDataInputStream data) { - Log.v(TAG, "restoreEntity"); + if (VERBOSE) Log.v(TAG, "restoreEntity"); if (mKeys == null) { mKeys = new ArrayList(); } @@ -223,10 +223,11 @@ public class LauncherBackupHelper implements BackupHelper { bytesRead = data.read(buffer, 0, dataSize); if (DEBUG) Log.d(TAG, "read " + bytesRead + " of " + dataSize + " available"); } catch (IOException e) { - Log.d(TAG, "failed to read entity from restore data", e); + Log.e(TAG, "failed to read entity from restore data", e); } try { key = backupKeyToKey(backupKey); + mKeys.add(key); switch (key.type) { case Key.FAVORITE: restoreFavorite(key, buffer, dataSize, mKeys); @@ -305,6 +306,8 @@ public class LauncherBackupHelper implements BackupHelper { if (!savedIds.contains(backupKey) || updateTime >= in.t) { byte[] blob = packFavorite(cursor); writeRowToBackup(key, blob, out, data); + } else { + if (VERBOSE) Log.v(TAG, "favorite " + id + " was too old: " + updateTime); } } } finally { @@ -328,12 +331,12 @@ public class LauncherBackupHelper implements BackupHelper { * @param keys keys to mark as clean in the notes for next backup */ private void restoreFavorite(Key key, byte[] buffer, int dataSize, ArrayList keys) { - Log.v(TAG, "unpacking favorite " + key.id + " (" + dataSize + " bytes)"); + if (VERBOSE) Log.v(TAG, "unpacking favorite " + key.id); if (DEBUG) Log.d(TAG, "read (" + buffer.length + "): " + Base64.encodeToString(buffer, 0, dataSize, Base64.NO_WRAP)); if (!mRestoreEnabled) { - if (DEBUG) Log.v(TAG, "restore not enabled: skipping database mutation"); + if (VERBOSE) Log.v(TAG, "restore not enabled: skipping database mutation"); return; } @@ -342,7 +345,7 @@ public class LauncherBackupHelper implements BackupHelper { ContentValues values = unpackFavorite(buffer, 0, dataSize); cr.insert(Favorites.CONTENT_URI, values); } catch (InvalidProtocolBufferNanoException e) { - Log.w(TAG, "failed to decode proto", e); + Log.e(TAG, "failed to decode favorite", e); } } @@ -370,7 +373,7 @@ public class LauncherBackupHelper implements BackupHelper { Set currentIds = new HashSet(cursor.getCount()); try { cursor.moveToPosition(-1); - Log.d(TAG, "dumping screens after: " + in.t); + if (DEBUG) Log.d(TAG, "dumping screens after: " + in.t); while(cursor.moveToNext()) { final long id = cursor.getLong(ID_INDEX); final long updateTime = cursor.getLong(ID_MODIFIED); @@ -381,9 +384,8 @@ public class LauncherBackupHelper implements BackupHelper { if (!savedIds.contains(backupKey) || updateTime >= in.t) { byte[] blob = packScreen(cursor); writeRowToBackup(key, blob, out, data); - if (DEBUG) Log.d(TAG, "wrote screen " + id); } else { - if (DEBUG) Log.d(TAG, "screen " + id + " was too old: " + updateTime); + if (VERBOSE) Log.v(TAG, "screen " + id + " was too old: " + updateTime); } } } finally { @@ -407,12 +409,12 @@ public class LauncherBackupHelper implements BackupHelper { * @param keys keys to mark as clean in the notes for next backup */ private void restoreScreen(Key key, byte[] buffer, int dataSize, ArrayList keys) { - Log.v(TAG, "unpacking screen " + key.id); + if (VERBOSE) Log.v(TAG, "unpacking screen " + key.id); if (DEBUG) Log.d(TAG, "read (" + buffer.length + "): " + Base64.encodeToString(buffer, 0, dataSize, Base64.NO_WRAP)); if (!mRestoreEnabled) { - if (DEBUG) Log.v(TAG, "restore not enabled: skipping database mutation"); + if (VERBOSE) Log.v(TAG, "restore not enabled: skipping database mutation"); return; } @@ -422,7 +424,7 @@ public class LauncherBackupHelper implements BackupHelper { cr.insert(WorkspaceScreens.CONTENT_URI, values); } catch (InvalidProtocolBufferNanoException e) { - Log.w(TAG, "failed to decode proto", e); + Log.e(TAG, "failed to decode screen", e); } } @@ -477,14 +479,14 @@ public class LauncherBackupHelper implements BackupHelper { Log.w(TAG, "empty intent on application favorite: " + id); } if (savedIds.contains(backupKey)) { - if (DEBUG) Log.d(TAG, "already saved icon " + backupKey); + if (VERBOSE) Log.v(TAG, "already saved icon " + backupKey); // remember that we already backed this up previously keys.add(key); } else if (backupKey != null) { if (DEBUG) Log.d(TAG, "I can count this high: " + out.rows); if ((out.rows - startRows) < MAX_ICONS_PER_PASS) { - if (DEBUG) Log.d(TAG, "saving icon " + backupKey); + if (VERBOSE) Log.v(TAG, "saving icon " + backupKey); Bitmap icon = iconCache.getIcon(intent); keys.add(key); if (icon != null && !iconCache.isDefaultIcon(icon)) { @@ -492,15 +494,15 @@ public class LauncherBackupHelper implements BackupHelper { writeRowToBackup(key, blob, out, data); } } else { - if (DEBUG) Log.d(TAG, "scheduling another run for icon " + backupKey); + if (VERBOSE) Log.d(TAG, "deferring icon backup " + backupKey); // too many icons for this pass, request another. dataChanged(); } } } catch (URISyntaxException e) { - Log.w(TAG, "invalid URI on application favorite: " + id); + Log.e(TAG, "invalid URI on application favorite: " + id); } catch (IOException e) { - Log.w(TAG, "unable to save application icon for favorite: " + id); + Log.e(TAG, "unable to save application icon for favorite: " + id); } } @@ -525,13 +527,13 @@ public class LauncherBackupHelper implements BackupHelper { * @param keys keys to mark as clean in the notes for next backup */ private void restoreIcon(Key key, byte[] buffer, int dataSize, ArrayList keys) { - Log.v(TAG, "unpacking icon " + key.id); + if (VERBOSE) Log.v(TAG, "unpacking icon " + key.id); if (DEBUG) Log.d(TAG, "read (" + buffer.length + "): " + Base64.encodeToString(buffer, 0, dataSize, Base64.NO_WRAP)); try { Resource res = unpackIcon(buffer, 0, dataSize); - if (DEBUG) Log.d(TAG, "unpacked " + res.dpi); - if (DEBUG) Log.d(TAG, "read " + + if (DEBUG) Log.d(TAG, "unpacked " + res.dpi + " dpi icon"); + if (DEBUG_PAYLOAD) Log.d(TAG, "read " + Base64.encodeToString(res.data, 0, res.data.length, Base64.NO_WRAP)); Bitmap icon = BitmapFactory.decodeByteArray(res.data, 0, res.data.length); @@ -540,13 +542,13 @@ public class LauncherBackupHelper implements BackupHelper { } if (!mRestoreEnabled) { - if (DEBUG) Log.v(TAG, "restore not enabled: skipping database mutation"); + if (VERBOSE) Log.v(TAG, "restore not enabled: skipping database mutation"); return; } else { // future site of icon cache mutation } } catch (InvalidProtocolBufferNanoException e) { - Log.w(TAG, "failed to decode proto", e); + Log.e(TAG, "failed to decode icon", e); } } @@ -605,14 +607,14 @@ public class LauncherBackupHelper implements BackupHelper { Log.w(TAG, "empty intent on appwidget: " + id); } if (savedIds.contains(backupKey)) { - if (DEBUG) Log.d(TAG, "already saved widget " + backupKey); + if (VERBOSE) Log.v(TAG, "already saved widget " + backupKey); // remember that we already backed this up previously keys.add(key); } else if (backupKey != null) { if (DEBUG) Log.d(TAG, "I can count this high: " + out.rows); if ((out.rows - startRows) < MAX_WIDGETS_PER_PASS) { - if (DEBUG) Log.d(TAG, "saving widget " + backupKey); + if (VERBOSE) Log.v(TAG, "saving widget " + backupKey); previewLoader.setPreviewSize(spanX * profile.cellWidthPx, spanY * profile.cellHeightPx, widgetSpacingLayout); byte[] blob = packWidget(dpi, previewLoader, iconCache, provider); @@ -620,7 +622,7 @@ public class LauncherBackupHelper implements BackupHelper { writeRowToBackup(key, blob, out, data); } else { - if (DEBUG) Log.d(TAG, "scheduling another run for widget " + backupKey); + if (VERBOSE) Log.d(TAG, "deferring widget backup " + backupKey); // too many widgets for this pass, request another. dataChanged(); } @@ -647,7 +649,7 @@ public class LauncherBackupHelper implements BackupHelper { * @param keys keys to mark as clean in the notes for next backup */ private void restoreWidget(Key key, byte[] buffer, int dataSize, ArrayList keys) { - Log.v(TAG, "unpacking widget " + key.id); + if (VERBOSE) Log.v(TAG, "unpacking widget " + key.id); if (DEBUG) Log.d(TAG, "read (" + buffer.length + "): " + Base64.encodeToString(buffer, 0, dataSize, Base64.NO_WRAP)); try { @@ -662,13 +664,13 @@ public class LauncherBackupHelper implements BackupHelper { } if (!mRestoreEnabled) { - if (DEBUG) Log.v(TAG, "restore not enabled: skipping database mutation"); + if (VERBOSE) Log.v(TAG, "restore not enabled: skipping database mutation"); return; } else { // future site of widget table mutation } } catch (InvalidProtocolBufferNanoException e) { - Log.w(TAG, "failed to decode proto", e); + Log.e(TAG, "failed to decode widget", e); } } @@ -807,7 +809,8 @@ public class LauncherBackupHelper implements BackupHelper { throws InvalidProtocolBufferNanoException { Favorite favorite = new Favorite(); MessageNano.mergeFrom(favorite, readCheckedBytes(buffer, offset, dataSize)); - if (DEBUG) Log.d(TAG, "unpacked " + favorite.itemType + ", " + favorite.id); + if (VERBOSE) Log.v(TAG, "unpacked favorite " + favorite.itemType + ", " + + (TextUtils.isEmpty(favorite.title) ? favorite.id : favorite.title)); ContentValues values = new ContentValues(); values.put(Favorites._ID, favorite.id); values.put(Favorites.SCREEN, favorite.screen); @@ -856,7 +859,7 @@ public class LauncherBackupHelper implements BackupHelper { throws InvalidProtocolBufferNanoException { Screen screen = new Screen(); MessageNano.mergeFrom(screen, readCheckedBytes(buffer, offset, dataSize)); - if (DEBUG) Log.d(TAG, "unpacked " + screen.id + "/" + screen.rank); + if (VERBOSE) Log.v(TAG, "unpacked screen " + screen.id + "/" + screen.rank); ContentValues values = new ContentValues(); values.put(WorkspaceScreens._ID, screen.id); values.put(WorkspaceScreens.SCREEN_RANK, screen.rank); @@ -879,6 +882,7 @@ public class LauncherBackupHelper implements BackupHelper { throws InvalidProtocolBufferNanoException { Resource res = new Resource(); MessageNano.mergeFrom(res, readCheckedBytes(buffer, offset, dataSize)); + if (VERBOSE) Log.v(TAG, "unpacked icon " + res.dpi + "/" + res.data.length); return res; } @@ -917,6 +921,7 @@ public class LauncherBackupHelper implements BackupHelper { throws InvalidProtocolBufferNanoException { Widget widget = new Widget(); MessageNano.mergeFrom(widget, readCheckedBytes(buffer, offset, dataSize)); + if (VERBOSE) Log.v(TAG, "unpacked widget " + widget.provider); return widget; } @@ -942,6 +947,7 @@ public class LauncherBackupHelper implements BackupHelper { byte[] buffer = new byte[availableBytes]; int bytesRead = 0; boolean valid = false; + InvalidProtocolBufferNanoException lastProtoException = null; while (availableBytes > 0) { try { // OMG what are you doing? This is crazy inefficient! @@ -961,7 +967,6 @@ public class LauncherBackupHelper implements BackupHelper { availableBytes = 0; } } catch (IOException e) { - Log.e(TAG, "failed to read the journal", e); buffer = null; availableBytes = 0; } @@ -972,23 +977,25 @@ public class LauncherBackupHelper implements BackupHelper { // if we are here, then we have read a valid, checksum-verified journal valid = true; availableBytes = 0; + if (VERBOSE) Log.v(TAG, "read " + bytesRead + " bytes of journal"); } catch (InvalidProtocolBufferNanoException e) { // if we don't have the whole journal yet, mergeFrom will throw. keep going. + lastProtoException = e; journal.clear(); } } if (DEBUG) Log.d(TAG, "journal bytes read: " + bytesRead); if (!valid) { - Log.w(TAG, "failed to read the journal: could not find a valid journal"); + Log.w(TAG, "could not find a valid journal", lastProtoException); } } } catch (IOException e) { - Log.d(TAG, "failed to close the journal", e); + Log.w(TAG, "failed to close the journal", e); } finally { try { inStream.close(); } catch (IOException e) { - Log.d(TAG, "failed to close the journal", e); + Log.w(TAG, "failed to close the journal", e); } } return journal; @@ -1001,7 +1008,7 @@ public class LauncherBackupHelper implements BackupHelper { data.writeEntityData(blob, blob.length); out.rows++; out.bytes += blob.length; - Log.v(TAG, "saving " + geKeyType(key) + " " + backupKey + ": " + + if (VERBOSE) Log.v(TAG, "saving " + geKeyType(key) + " " + backupKey + ": " + getKeyName(key) + "/" + blob.length); if(DEBUG_PAYLOAD) { String encoded = Base64.encodeToString(blob, 0, blob.length, Base64.NO_WRAP); @@ -1009,7 +1016,7 @@ public class LauncherBackupHelper implements BackupHelper { for (int offset = 0; offset < encoded.length(); offset += chunkSize) { int end = offset + chunkSize; end = Math.min(end, encoded.length()); - Log.d(TAG, "wrote " + encoded.substring(offset, end)); + Log.w(TAG, "wrote " + encoded.substring(offset, end)); } } } @@ -1029,7 +1036,7 @@ public class LauncherBackupHelper implements BackupHelper { throws IOException { int rows = 0; for(String deleted: deletedIds) { - Log.v(TAG, "dropping icon " + deleted); + if (VERBOSE) Log.v(TAG, "dropping deleted item " + deleted); data.writeEntityHeader(deleted, -1); rows++; } @@ -1050,11 +1057,11 @@ public class LauncherBackupHelper implements BackupHelper { try { outStream = new FileOutputStream(newState.getFileDescriptor()); final byte[] journalBytes = writeCheckedBytes(journal); - if (DEBUG) Log.d(TAG, "writing " + journalBytes.length + " bytes of journal"); outStream.write(journalBytes); outStream.close(); + if (VERBOSE) Log.v(TAG, "wrote " + journalBytes.length + " bytes of journal"); } catch (IOException e) { - Log.d(TAG, "failed to write backup journal", e); + Log.w(TAG, "failed to write backup journal", e); } } diff --git a/src/com/android/launcher3/LauncherPreferencesBackupHelper.java b/src/com/android/launcher3/LauncherPreferencesBackupHelper.java index 1ac6ff962..6f9c05c88 100644 --- a/src/com/android/launcher3/LauncherPreferencesBackupHelper.java +++ b/src/com/android/launcher3/LauncherPreferencesBackupHelper.java @@ -19,9 +19,13 @@ package com.android.launcher3; import android.app.backup.BackupDataInputStream; import android.app.backup.SharedPreferencesBackupHelper; import android.content.Context; +import android.util.Log; public class LauncherPreferencesBackupHelper extends SharedPreferencesBackupHelper { + private static final String TAG = "LauncherPreferencesBackupHelper"; + private static final boolean VERBOSE = LauncherBackupAgentHelper.VERBOSE; + private final boolean mRestoreEnabled; public LauncherPreferencesBackupHelper(Context context, String sharedPreferencesKey, @@ -33,6 +37,7 @@ public class LauncherPreferencesBackupHelper extends SharedPreferencesBackupHelp @Override public void restoreEntity(BackupDataInputStream data) { if (mRestoreEnabled) { + if (VERBOSE) Log.v(TAG, "restoring preferences"); super.restoreEntity(data); } } -- cgit v1.2.3