Lots of "GeckoFavicons: Cancelling favicon load (NN)" spew in logcat

RESOLVED FIXED in Firefox 31

Status

()

defect
RESOLVED FIXED
5 years ago
5 years ago

People

(Reporter: emorley, Assigned: rnewman)

Tracking

Trunk
Firefox 31
All
Android
Points:
---
Dependency tree / graph

Firefox Tracking Flags

(Not tracked)

Details

Bug 699786 added:
https://hg.mozilla.org/mozilla-central/file/b735e618c2a8/mobile/android/base/favicons/Favicons.java#l334
>   334             Log.d(LOGTAG, "Cancelling favicon load (" + taskId + ")");

This causes quite a lot of noise in the logcats during automation test runs, eg look in:
https://tbpl.mozilla.org/php/getParsedLog.php?id=37956010&tree=Mozilla-Inbound
14:59:29     INFO -  --------- beginning of /dev/log/main
14:59:29     INFO -  04-16 14:57:14.492 E/GeckoConsole( 2119): [JavaScript Warning: "An unbalanced tree was written using document.write() causing data from the network to be reparsed. For more information https://developer.mozilla.org/en/Optimizing_Your_Pages_for_Speculative_Parsing" {file: "http://10.12.129.21:30222/jsreftest/tests/jsreftest.html?test=test262/ch13/13.0/S13_A6_T1.js" line: 15}]
14:59:29     INFO -  04-16 14:57:15.093 I/GeckoDump( 2119):  PASSED!
14:59:29     INFO -  04-16 14:57:15.109 E/GeckoConsole( 2119): [JavaScript Warning: "An unbalanced tree was written using document.write() causing data from the network to be reparsed. For more information https://developer.mozilla.org/en/Optimizing_Your_Pages_for_Speculative_Parsing" {file: "http://10.12.129.21:30222/jsreftest/tests/jsreftest.html?test=test262/ch13/13.0/S13_A6_T2.js" line: 15}]
14:59:29     INFO -  04-16 14:57:15.687 I/GeckoDump( 2119):  PASSED!
14:59:29     INFO -  04-16 14:57:15.695 D/GeckoFavicons( 2119): Cancelling favicon load (15638)
14:59:29     INFO -  04-16 14:57:15.695 D/GeckoFavicons( 2119): Cancelling favicon load (15639)
14:59:29     INFO -  04-16 14:57:15.695 D/GeckoFavicons( 2119): Cancelling favicon load (15640)
14:59:29     INFO -  04-16 14:57:15.695 D/GeckoFavicons( 2119): Cancelling favicon load (15641)
14:59:29     INFO -  04-16 14:57:15.695 D/GeckoFavicons( 2119): Cancelling favicon load (15642)
14:59:29     INFO -  04-16 14:57:15.695 D/GeckoFavicons( 2119): Cancelling favicon load (15643)
14:59:29     INFO -  04-16 14:57:15.695 E/GeckoConsole( 2119): [JavaScript Warning: "An unbalanced tree was written using document.write() causing data from the network to be reparsed. For more information https://developer.mozilla.org/en/Optimizing_Your_Pages_for_Speculative_Parsing" {file: "http://10.12.129.21:30222/jsreftest/tests/jsreftest.html?test=test262/ch13/13.0/S13_A7_T1.js" line: 15}]
14:59:29     INFO -  04-16 14:57:16.101 I/GeckoDump( 2119):  PASSED!
14:59:29     INFO -  04-16 14:57:16.109 E/GeckoConsole( 2119): [JavaScript Warning: "An unbalanced tree was written using document.write() causing data from the network to be reparsed. For more information https://developer.mozilla.org/en/Optimizing_Your_Pages_for_Speculative_Parsing" {file: "http://10.12.129.21:30222/jsreftest/tests/jsreftest.html?test=test262/ch13/13.0/S13_A7_T2.js" line: 15}]
14:59:29     INFO -  04-16 14:57:16.390 D/GeckoFavicons( 2119): Cancelling favicon load (15646)
14:59:29     INFO -  04-16 14:57:16.390 D/GeckoFavicons( 2119): Cancelling favicon load (15647)
14:59:29     INFO -  04-16 14:57:16.390 D/GeckoFavicons( 2119): Cancelling favicon load (15648)
14:59:29     INFO -  04-16 14:57:16.390 D/GeckoFavicons( 2119): Cancelling favicon load (15649)
14:59:29     INFO -  04-16 14:57:16.390 D/GeckoFavicons( 2119): Cancelling favicon load (15650)
14:59:29     INFO -  04-16 14:57:16.390 D/GeckoFavicons( 2119): Cancelling favicon load (15651)
14:59:29     INFO -  04-16 14:57:16.851 D/GeckoFavicons( 2119): Cancelling favicon load (15654)
14:59:29     INFO -  04-16 14:57:16.851 D/GeckoFavicons( 2119): Cancelling favicon load (15655)
14:59:29     INFO -  04-16 14:57:16.851 D/GeckoFavicons( 2119): Cancelling favicon load (15656)
14:59:29     INFO -  04-16 14:57:16.851 D/GeckoFavicons( 2119): Cancelling favicon load (15657)
14:59:29     INFO -  04-16 14:57:16.851 D/GeckoFavicons( 2119): Cancelling favicon load (15658)
14:59:29     INFO -  04-16 14:57:16.851 D/GeckoFavicons( 2119): Cancelling favicon load (15659)
14:59:29     INFO -  04-16 14:57:17.375 D/GeckoFavicons( 2119): Cancelling favicon load (15662)
14:59:29     INFO -  04-16 14:57:17.382 D/GeckoFavicons( 2119): Cancelling favicon load (15663)
14:59:29     INFO -  04-16 14:57:17.382 D/GeckoFavicons( 2119): Cancelling favicon load (15664)
14:59:29     INFO -  04-16 14:57:17.382 D/GeckoFavicons( 2119): Cancelling favicon load (15665)
14:59:29     INFO -  04-16 14:57:17.382 D/GeckoFavicons( 2119): Cancelling favicon load (15666)
14:59:29     INFO -  04-16 14:57:17.382 D/GeckoFavicons( 2119): Cancelling favicon load (15667)
14:59:29     INFO -  04-16 14:57:17.578 I/GeckoDump( 2119):  PASSED!
(...)

The log only saves the last N lines of the logcat (failing that we have to resort to the blobuploader, but this is active on the pandas only), so logcat spam can push the important lines out.

Do we need these log dumps still? Also, is it expected to have so many favicon load cancellations?
Flags: needinfo?(lucasr.at.mozilla)
It's not a bad thing -- it implies that we're opening and closing 15,000 pages faster than we can load the favicons -- but those should be verbose-level, not debug.
Assignee: nobody → rnewman
Flags: needinfo?(lucasr.at.mozilla)
Hardware: ARM → All
Status: NEW → ASSIGNED
Thank you :-)
Summary: Lots of "GeckoConsole: Cancelling favicon load (NN)" spew in logcat → Lots of "GeckoFavicons: Cancelling favicon load (NN)" spew in logcat
https://hg.mozilla.org/integration/fx-team/rev/e386f9ef145d

Ed, is this something you want to uplift for sanity's sake?
Component: General → Favicon Handling
(In reply to Richard Newman [:rnewman] from comment #3)
> Ed, is this something you want to uplift for sanity's sake?

I think we'll be fine - thank you for landing that :-)
https://hg.mozilla.org/mozilla-central/rev/e386f9ef145d
Status: ASSIGNED → RESOLVED
Closed: 5 years ago
Resolution: --- → FIXED
Target Milestone: --- → Firefox 31
You need to log in before you can comment on or make changes to this bug.