Closed
Bug 804457
Opened 12 years ago
Closed 12 years ago
Reduce log chattiness
Categories
(Firefox for Android Graveyard :: General, defect)
Tracking
(Not tracked)
RESOLVED
FIXED
Firefox 19
People
(Reporter: rnewman, Assigned: rnewman)
References
Details
Attachments
(2 files, 3 obsolete files)
32.15 KB,
patch
|
mfinkle
:
review+
|
Details | Diff | Splinter Review |
41.61 KB,
patch
|
mfinkle
:
review+
|
Details | Diff | Splinter Review |
No description provided.
Assignee | ||
Comment 1•12 years ago
|
||
Comment 2•12 years ago
|
||
Comment on attachment 674111 [details] [diff] [review]
Part 1: spelling, grammar, punctuation, and log levels in GeckoApp.java. v1
>diff --git a/mobile/android/base/GeckoApp.java b/mobile/android/base/GeckoApp.java
In general, I would skip the pure comment changes, just to minimimze bitrot to other devs. My requests to remove might be a bit aggressive, but I am considering just how useful this output is to external users. Internal devs can just add their own logs as needed... and then remove them. The "zerdatime" stuff is not helpful anymore.
>- Log.w(LOGTAG, "zerdatime " + SystemClock.uptimeMillis() + " - start of getPluginDirectories");
>+ Log.d(LOGTAG, "zerdatime " + SystemClock.uptimeMillis() + " - start of getPluginDirectories");
I'd be happier to see these "zerdatime" logs go away. We are using telemetry to gather timing
>- Log.w(LOGTAG, "Loading plugin: " + serviceInfo.packageName);
>-
>-
>- // retrieve information from the plugin's manifest
>+ Log.d(LOGTAG, "Loading plugin: " + serviceInfo.packageName);
Let's remove these "You are here" logs
>- Log.w(LOGTAG, "zerdatime " + SystemClock.uptimeMillis() + " - end of getPluginDirectories");
>+ Log.d(LOGTAG, "zerdatime " + SystemClock.uptimeMillis() + " - end of getPluginDirectories");
Remove
> protected void onSaveInstanceState(Bundle outState) {
>- Log.i(LOGTAG, "onSaveInstanceState");
>+ Log.d(LOGTAG, "Entered onSaveInstanceState.");
More "You are here". Remove.
>+ /**
>+ * This function might perform synchronous IO. Don't call it
>+ * from the main thread.
>+ */
> public StartupMode getStartupMode() {
>- // This function might touch the disk and should not
>- // be called from UI's main thread.
Good comment change
> public void handleMessage(String event, JSONObject message) {
>- Log.i(LOGTAG, "Got message: " + event);
>+ Log.d(LOGTAG, "Got message: " + event);
I have not seen any value in this log. I vote to remove it.
> for (int i = 0; i < aPermissions.length(); i++) {
> try {
>- items[i] = aPermissions.getJSONObject(i).
>- getString("setting");
>- // Make all the items checked by default
>+ items[i] = aPermissions.getJSONObject(i).getString("setting");
>+ // Make all the items checked by default.
Yeah. I like this too.
> mMainHandler = new Handler();
>- Log.w(LOGTAG, "zerdatime " + SystemClock.uptimeMillis() + " - onCreate");
>+ Log.d(LOGTAG, "zerdatime " + SystemClock.uptimeMillis() + " - onCreate");
Burn it.
> if (savedInstanceState != null) {
>- Log.i(LOGTAG, "Restoring from OOM");
>+ Log.i(LOGTAG, "Restoring from OOM.");
Burn it.
> boolean wasInBackground =
> savedInstanceState.getBoolean(SAVED_STATE_IN_BACKGROUND, false);
>- Log.i(LOGTAG, "Was in background: " + wasInBackground);
>+ Log.d(LOGTAG, "Was in background: " + wasInBackground);
Burn it.
> boolean wasOOM = prefs.getBoolean(PREFS_OOM_EXCEPTION, false);
> boolean wasStopped = prefs.getBoolean(PREFS_WAS_STOPPED, true);
> if (wasOOM || !wasStopped) {
>- Log.i(LOGTAG, "Crashed due to OOM last run");
>+ Log.i(LOGTAG, "Crashed due to OOM on last run.");
Burn it.
> if (mRestoreMode == GeckoAppShell.RESTORE_NONE && getProfile().shouldRestoreSession()) {
>- Log.i(LOGTAG, "Restoring crash");
>+ Log.d(LOGTAG, "Restoring crash.");
Burn it.
> } else if (ACTION_DEBUG.equals(action) &&
> checkAndSetLaunchState(LaunchState.Launching, LaunchState.WaitForDebugger)) {
> mMainHandler.postDelayed(new Runnable() {
> public void run() {
>- Log.i(LOGTAG, "Launching from debug intent after 5s wait");
>+ Log.d(LOGTAG, "Launching from debug intent after 5s wait");
> setLaunchState(LaunchState.Launching);
> sGeckoThread.start();
> }
> }, 1000 * 5 /* 5 seconds */);
>- Log.i(LOGTAG, "Intent : ACTION_DEBUG - waiting 5s before launching");
>+ Log.d(LOGTAG, "Intent : ACTION_DEBUG - waiting 5s before launching");
These seem useless too, but we probably never see them anyway.
>- Log.w(LOGTAG, "zerdatime " + SystemClock.uptimeMillis() + " - UI almost up");
>+ Log.d(LOGTAG, "zerdatime " + SystemClock.uptimeMillis() + " - UI almost up");
Remove
> GeckoAppShell.getHandler().postDelayed(new Runnable() {
> public void run() {
>- Log.w(LOGTAG, "zerdatime " + SystemClock.uptimeMillis() + " - pre checkLaunchState");
>+ Log.d(LOGTAG, "zerdatime " + SystemClock.uptimeMillis() + " - pre checkLaunchState");
Remove
> // Kick off our background service to fetch product announcements.
> // We do this by invoking the broadcast receiver, which uses the
> // system alarm infrastructure to perform tasks at intervals.
> Log.d(LOGTAG, "Broadcasting announcements pref.");
This seems like a "You are here" debugging output.
> protected void onNewIntent(Intent intent) {
>- Log.w(LOGTAG, "zerdatime " + SystemClock.uptimeMillis() + " - onNewIntent");
>+ Log.d(LOGTAG, "zerdatime " + SystemClock.uptimeMillis() + " - onNewIntent");
Remove
> if (Intent.ACTION_MAIN.equals(action)) {
>- Log.i(LOGTAG, "Intent : ACTION_MAIN");
>+ Log.d(LOGTAG, "Intent: ACTION_MAIN");
Remove
> public void onResume()
> {
>- Log.i(LOGTAG, "resume");
>+ Log.d(LOGTAG, "Entering onResume.");
Remove
> public void onStop()
> {
>- Log.i(LOGTAG, "stop");
>+ Log.d(LOGTAG, "Entering onStop.");
Remove
> public void onPause()
> {
>- Log.i(LOGTAG, "pause");
>+ Log.d(LOGTAG, "Entering onPause.");
Remove
> public void onRestart()
> {
>- Log.i(LOGTAG, "restart");
>+ Log.d(LOGTAG, "Entering onRestart.");
Remove
> public void onStart()
> {
>- Log.w(LOGTAG, "zerdatime " + SystemClock.uptimeMillis() + " - onStart");
>-
>- Log.i(LOGTAG, "start");
>+ Log.d(LOGTAG, "zerdatime " + SystemClock.uptimeMillis() + " - onStart");
Remove
> public void onDestroy()
> {
>- Log.i(LOGTAG, "destroy");
>+ Log.d(LOGTAG, "Entering onDestroy.");
Remove
> public void onConfigurationChanged(Configuration newConfig)
> {
>- Log.i(LOGTAG, "configuration changed");
>+ Log.d(LOGTAG, "Configuration changed.");
Remove
> public void doRestart(String action) {
>- Log.i(LOGTAG, "doRestart(\"" + action + "\")");
>+ Log.d(LOGTAG, "doRestart(\"" + action + "\")");
Remove
>- Log.i(LOGTAG, intent.toString());
>+ Log.d(LOGTAG, "Restart intent: " + intent.toString());
Remove
>- Log.i(LOGTAG, "Checking profile migration in: " + profileDir.getAbsolutePath());
>+ Log.d(LOGTAG, "Checking profile migration in: " + profileDir.getAbsolutePath());
Remove
> long timeDiff = SystemClock.uptimeMillis() - currentTime;
>- Log.i(LOGTAG, "Profile migration took " + timeDiff + " ms");
>+ Log.v(LOGTAG, "Profile migration took " + timeDiff + " ms");
Is this useful anymore? I don't think it is. Remove the log and timing code.
> if (!profileMigrator.hasSyncMigrated()) {
>- Log.i(LOGTAG, "Checking Sync settings in: " + profileDir.getAbsolutePath());
>+ Log.d(LOGTAG, "Checking Sync settings in: " + profileDir.getAbsolutePath());
Remove
Thoughts?
Attachment #674111 -
Flags: review?(mark.finkle) → review-
Assignee | ||
Comment 3•12 years ago
|
||
Now with 300% fewer nitpicky comment changes, and ∞ less zerdatime.
Attachment #674111 -
Attachment is obsolete: true
Attachment #674123 -
Flags: review?(mark.finkle)
Comment 4•12 years ago
|
||
Comment on attachment 674123 [details] [diff] [review]
Part 1: spelling, grammar, punctuation, and log levels in GeckoApp.java. v2
Worth it
Attachment #674123 -
Flags: review?(mark.finkle) → review+
Comment 5•12 years ago
|
||
Try run for b41d581399f0 is complete.
Detailed breakdown of the results available here:
https://tbpl.mozilla.org/?tree=Try&rev=b41d581399f0
Results (out of 48 total builds):
success: 40
warnings: 5
failure: 3
Builds (or logs if builds failed) available at:
http://ftp.mozilla.org/pub/mozilla.org/firefox/try-builds/rnewman@mozilla.com-b41d581399f0
Assignee | ||
Comment 6•12 years ago
|
||
https://hg.mozilla.org/integration/mozilla-inbound/rev/7b01f6cf02b4
Parts 2+ are open to community participation, unless I get to them tonight :D
Target Milestone: --- → Firefox 19
Assignee | ||
Comment 7•12 years ago
|
||
(Still building; I'll wait for that before I land, assuming r+!)
Touched most of the other noisy classes, taking the same approach.
In a couple of spots where I broke a lot of blame/patch application, I took the opportunity to improve the code; you'll see the places. Happy to rip those out if you don't want to take them.
Attachment #674484 -
Flags: review?(mark.finkle)
Comment 8•12 years ago
|
||
Status: ASSIGNED → RESOLVED
Closed: 12 years ago
Flags: in-testsuite-
Resolution: --- → FIXED
Assignee | ||
Comment 9•12 years ago
|
||
How 'bout I use correct Java syntax?
Attachment #674484 -
Attachment is obsolete: true
Attachment #674484 -
Flags: review?(mark.finkle)
Attachment #674529 -
Flags: review?(mark.finkle)
Comment 10•12 years ago
|
||
Comment on attachment 674529 [details] [diff] [review]
Part 2: hit other classes. v2
Review of attachment 674529 [details] [diff] [review]:
-----------------------------------------------------------------
::: mobile/android/base/BrowserToolbar.java
@@ -556,5 @@
> if (visible) {
> mFavicon.setImageDrawable(mProgressSpinner);
> mProgressSpinner.start();
> setPageActionVisibility(true);
> - Log.i(LOGTAG, "zerdatime " + SystemClock.uptimeMillis() + " - Throbber start");
I think the "Throbber start" and "Throbber stop" messages are used by S1/S2 tests (http://mrcote.info/phonedash/#) - we probably need to leave them in.
Comment 11•12 years ago
|
||
(In reply to Geoff Brown [:gbrown] from comment #10)
> Comment on attachment 674529 [details] [diff] [review]
> Part 2: hit other classes. v2
>
> Review of attachment 674529 [details] [diff] [review]:
> -----------------------------------------------------------------
>
> ::: mobile/android/base/BrowserToolbar.java
> @@ -556,5 @@
> > if (visible) {
> > mFavicon.setImageDrawable(mProgressSpinner);
> > mProgressSpinner.start();
> > setPageActionVisibility(true);
> > - Log.i(LOGTAG, "zerdatime " + SystemClock.uptimeMillis() + " - Throbber start");
>
> I think the "Throbber start" and "Throbber stop" messages are used by S1/S2
> tests (http://mrcote.info/phonedash/#) - we probably need to leave them in.
Indeed, but I was wondering if we could remove the "zerdatime" and millisec parts. Does phonedash use the times too, or just the "Throbber Start/Stop" text?
Assignee | ||
Comment 12•12 years ago
|
||
> > I think the "Throbber start" and "Throbber stop" messages are used by S1/S2
> > tests (http://mrcote.info/phonedash/#) - we probably need to leave them in.
Good to know, thanks Geoff.
> Indeed, but I was wondering if we could remove the "zerdatime" and millisec
> parts. Does phonedash use the times too, or just the "Throbber Start/Stop"
> text?
And also: does this have to log at INFO? And if it really is used by a test somewhere, I'll add a comment to that effect.
Is there a doc somewhere for what that test needs?
Comment 13•12 years ago
|
||
(In reply to Mark Finkle (:mfinkle) from comment #11)
> (In reply to Geoff Brown [:gbrown] from comment #10)
> Indeed, but I was wondering if we could remove the "zerdatime" and millisec
> parts. Does phonedash use the times too, or just the "Throbber Start/Stop"
> text?
It uses the times too.
It does not look for "zerdatime" specifically, but it extracts the millisec times from the nth space-delimited word -- so "zerdatime" can be changed to something else, but it you remove it entirely, the tests will break.
Code is here: https://github.com/mozilla/autophone/blob/master/tests/s1s2test.py#L142
I don't think INFO is necessary. I don't know of any doc.
Assignee | ||
Comment 14•12 years ago
|
||
(In reply to Geoff Brown [:gbrown] from comment #13)
> It uses the times too.
I'm going to strip that change out of this patch, add a comment about it being necessary for that test, and file a follow-up bug to do this in a less janky way.
Assignee | ||
Comment 15•12 years ago
|
||
Attachment #674529 -
Attachment is obsolete: true
Attachment #674529 -
Flags: review?(mark.finkle)
Attachment #674771 -
Flags: review?(mark.finkle)
Comment 16•12 years ago
|
||
Comment on attachment 674771 [details] [diff] [review]
Part 2: hit other classes. v3
>- Log.i(LOGTAG, "post native init");
>+ Log.v(LOGTAG, "Native init spawned.");
Remove
>- Log.i(LOGTAG, "Location provider - high accuracy: " + enable);
>+ Log.v(LOGTAG, "Location provider - high accuracy: " + enable);
>- Log.i(LOGTAG, "Enabling SENSOR_ORIENTATION");
>+ Log.v(LOGTAG, "Enabling SENSOR_ORIENTATION");
>- Log.i(LOGTAG, "Enabling SENSOR_ACCELERATION");
>+ Log.v(LOGTAG, "Enabling SENSOR_ACCELERATION");
>- Log.i(LOGTAG, "Enabling SENSOR_PROXIMITY");
>+ Log.v(LOGTAG, "Enabling SENSOR_PROXIMITY");
>- Log.i(LOGTAG, "Enabling SENSOR_LIGHT");
>+ Log.v(LOGTAG, "Enabling SENSOR_LIGHT");
>- Log.i(LOGTAG, "Enabling SENSOR_LINEAR_ACCELERATION");
>+ Log.v(LOGTAG, "Enabling SENSOR_LINEAR_ACCELERATION");
>- Log.i(LOGTAG, "Enabling SENSOR_GYROSCOPE");
>+ Log.v(LOGTAG, "Enabling SENSOR_GYROSCOPE");
Remove
>- Log.i(LOGTAG, "Disabling SENSOR_ORIENTATION");
>+ Log.v(LOGTAG, "Disabling SENSOR_ORIENTATION");
>- Log.i(LOGTAG, "Disabling SENSOR_ACCELERATION");
>+ Log.v(LOGTAG, "Disabling SENSOR_ACCELERATION");
>- Log.i(LOGTAG, "Disabling SENSOR_PROXIMITY");
>+ Log.v(LOGTAG, "Disabling SENSOR_PROXIMITY");
>- Log.i(LOGTAG, "Disabling SENSOR_LIGHT");
>+ Log.v(LOGTAG, "Disabling SENSOR_LIGHT");
>- Log.i(LOGTAG, "Disabling SENSOR_LINEAR_ACCELERATION");
>+ Log.v(LOGTAG, "Disabling SENSOR_LINEAR_ACCELERATION");
>- Log.i(LOGTAG, "Disabling SENSOR_GYROSCOPE");
>+ Log.v(LOGTAG, "Disabling SENSOR_GYROSCOPE");
Let's remove these too
> static void scheduleRestart() {
>- Log.i(LOGTAG, "scheduling restart");
>+ Log.v(LOGTAG, "Scheduling restart.");
Remove
> public static void addPluginView(View view,
>- Log.i(LOGTAG, "addPluginView:" + view + " @ x:" + x + " y:" + y + " w:" + w + " h:" + h + " fullscreen: " + isFullScreen);
>+ Log.d(LOGTAG, "addPluginView:" + view + " @ x:" + x + " y:" + y + " w:" + w + " h:" + h + " fullscreen: " + isFullScreen);
> public static void removePluginView(View view, boolean isFullScreen) {
>- Log.i(LOGTAG, "removePluginView:" + view + " fullscreen: " + isFullScreen);
>+ Log.d(LOGTAG, "removePluginView:" + view + " fullscreen: " + isFullScreen);
> GeckoApp.mAppContext.removePluginView(view, isFullScreen);
> }
>
> public static Class<?> loadPluginClass(String className, String libName) {
>- Log.i(LOGTAG, "in loadPluginClass... attempting to access className, then libName.....");
>- Log.i(LOGTAG, "className: " + className);
>- Log.i(LOGTAG, "libName: " + libName);
>-
>+ Log.d(LOGTAG, "loadPluginClass(" + className + ", " + libName + ")");
Tempted to remove these. Seem like something we only want while debugging the app locally.
[Update: after reviewing the patch, let's remove these too]
> static int[] initCamera(String aContentType, int aCamera, int aWidth, int aHeight) {
>- Log.i(LOGTAG, "initCamera(" + aContentType + ", " + aWidth + "x" + aHeight + ") on thread " + Thread.currentThread().getId());
>+ Log.d(LOGTAG, "initCamera(" + aContentType + ", " + aWidth + "x" + aHeight + ") on thread " + Thread.currentThread().getId());
Same temptation. [Update: Remove]
>- Log.i(LOGTAG, "Camera: " + params.getPreviewSize().width + "x" + params.getPreviewSize().height +
>+ Log.v(LOGTAG, "Camera: " + params.getPreviewSize().width + "x" + params.getPreviewSize().height +
More of the same. [Update: Remove]
> static synchronized void closeCamera() {
>- Log.i(LOGTAG, "closeCamera() on thread " + Thread.currentThread().getId());
>+ Log.d(LOGTAG, "closeCamera() on thread " + Thread.currentThread().getId());
More (why do we do this kind of output?). [Update: Remove]
>diff --git a/mobile/android/base/Tabs.java b/mobile/android/base/Tabs.java
>- Log.i(LOGTAG, "Added a tab with id: " + id);
>+ Log.d(LOGTAG, "Added a tab with id: " + id);
Remove
>- Log.i(LOGTAG, "Removed a tab with id: " + id);
>+ Log.d(LOGTAG, "Removed a tab with id: " + id);
Remove
> public void handleMessage(String event, JSONObject message) {
>- Log.i(LOGTAG, "Got message: " + event);
>+ Log.d(LOGTAG, "Got message: " + event);
Remove
>diff --git a/mobile/android/base/gfx/LayerView.java b/mobile/android/base/gfx/LayerView.java
> public void setPaintState(int paintState) {
>- Log.d(LOGTAG, "LayerView paint state set to " + paintState);
>+ Log.v(LOGTAG, "LayerView paint state set to " + paintState);
Remove
Attachment #674771 -
Flags: review?(mark.finkle) → review+
Assignee | ||
Comment 17•12 years ago
|
||
Comment 18•12 years ago
|
||
Updated•4 years ago
|
Product: Firefox for Android → Firefox for Android Graveyard
You need to log in
before you can comment on or make changes to this bug.
Description
•