New issue
Advanced search Search tips
Note: Color blocks (like or ) mean that a user may not be available. Tooltip shows the reason.

Issue 843277 link

Starred by 2 users

Issue metadata

Status: Fixed
Owner:
Closed: Jul 31
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: Android
Pri: 3
Type: Bug



Sign in to add a comment

WebView Autofill: Consider to have log that can be turned on at runtime.

Project Member Reported by michaelbai@chromium.org, May 15 2018

Issue description

We probably should dump some Autofill log at runtime for debugging by using system property (same as framework used), it should be easy for QA or other team to do some initial debugging.

 
Project Member

Comment 1 by bugdroid1@chromium.org, Jun 8 2018

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/e12209c4ed4044eb12673013b3e8c59c165f4792

commit e12209c4ed4044eb12673013b3e8c59c165f4792
Author: Tao Bai <michaelbai@chromium.org>
Date: Fri Jun 08 00:04:40 2018

[WebView autofill] Add runtime log

The log can be enabled by run
setprop log.tag.AwAutofillManager DEBUG

Bug:  843277 
Change-Id: I136d300b4fa11e42b3acce0f41ad832b56ff9938
Reviewed-on: https://chromium-review.googlesource.com/1091302
Reviewed-by: Changwan Ryu <changwan@chromium.org>
Commit-Queue: Tao Bai <michaelbai@chromium.org>
Cr-Commit-Position: refs/heads/master@{#565472}
[modify] https://crrev.com/e12209c4ed4044eb12673013b3e8c59c165f4792/android_webview/java/src/org/chromium/android_webview/AwAutofillManager.java
[modify] https://crrev.com/e12209c4ed4044eb12673013b3e8c59c165f4792/android_webview/java/src/org/chromium/android_webview/AwAutofillProvider.java

You should not using a common function that checks for the logging level inside, otherwise you would be unnecessarily allocating strings at runtime when the logging is disabled. For example:

log("isAutofillInputUIShowing: " + mIsAutofillInputUIShowing);


You should instead use:

if (Log.isLoggable(TAG, Log.DEBUG)) {
    Log.d(TAG, "isAutofillInputUIShowing: " + mIsAutofillInputUIShowing);
}



Good catch!

Comment 4 by torne@chromium.org, Jun 11 2018

I'm not too sure about doing this in general at all - this mechanism of controlling logs is only used in one other place in the entirety of chromium and seems like it may add nontrivial overhead, even if each site is guarded individually - it has to go parse a system property over and over, and if I understand correctly this is code that is hit pretty often during input interactions?

Is there a very specific test case these logs are intended to address? Is it a specific issue being investigated right now that we can remove this code again once it's resolved, or are you intending this to stay here permanently?
It is intended to stay permanently.

I don't think anyone else uses this mechanism in chromium, isLoggable() call took 0.03ms, but I will no check it for every call, one check per autofill session should be fine.

Comment 6 by torne@chromium.org, Jun 12 2018

So what this is implementing is functionally similar to VLOG() in native code: additional logging that is compiled into release builds but turned off by default. It's been generally agreed for a good while that VLOG() should not be used, only DVLOG(), because the impact on the size and performance of release builds is undesirable for something that will virtually never be enabled. In general *all* logging in release builds is suspect and should be minimised.

I don't really see why we should handle Java-side logging differently, which is why I was asking if this is only temporary. I don't think we should add this permanently at all, no matter how you check isLoggable.

If we really do want to support this, we should probably talk with other base/android OWNERS about whether there's a general desire for a VLOG-alike for Java other than this existing android mechanism (which requires weird unrelated-to-chromium actions to enable), but I suspect the answer is going to be no due to the above.
Cc: agrieve@chromium.org rmcilroy@chromium.org nyquist@chromium.org yfried...@chromium.org
+ base/android owner, please check #6.

I think we has handled the java log differently (not call to native side), this is more efficient in terms of size and performance.

Comment 8 by torne@chromium.org, Jun 12 2018

The most efficient way to handle logging is always to omit it entirely in a release build :)
Background of the autofill runtime log

This feature was asked by Android framework team, Framework has ability to enable run time log (different way is used to enable.) for autofill, we found this is very helpful for framework, GMS and WebView team to debug issue, and 3rd party also use this for reporting issue to us, but the missing part was WebView.
I think it might be a reasonable thing to want to do, but it'd be nice to have some motivating examples. The commit in #1 looks a lot like printf debugging, which I don't think provides sufficient value to ship in release builds.

I generally agree with torne/agrieve. I would frame this as: what makes autofill a unique feature such as to warrant special treatment and needs extra care from "QA and other teams"?
I also can not see why we need this special case.
The reason to have this is that Autofill in Android framework have runtime log, it is very helpful for us to figure out where the issue locates, but when WebView is used, since there is no runtime log, the issues go back and forth among 3 teams, it isn't productive, WebView is a part of Android framework and should be consistent with it as possible as we can, this will also help for 3rd party autofill service.

The log currently is just simple call of autofill framework API, but reflects WebView's behavior, I think it is sufficient now, since Autofill is always related PII, we don't want output too much information.

Comment 14 by torne@chromium.org, Jun 14 2018

There are *far* more important things WebView could be optionally logging to behave like the framework and help framework developers debug issues: for example we currently don't log callbacks to our client interfaces unless a build-time flag is flipped. This seems very low down the priority list of things to spend bytes on.
I think the autofill is unique because

- WebView autofill's peer in Android framework uses runtime log.
- Android autofill runtime log has been widely used by framework, gms and our partner, and they will immediately benefit from WebView autofill's runtime log.
- This feature is required by real user.

Beside above, this is very little overheads
- added 0.03ms to each autofill session
- added 560 bytes to dex file, but no change to APK size.

Comment 16 by torne@chromium.org, Jun 15 2018

This is still a vanishingly rare special case compared to many other places in WebView that would have much more useful callbacks. I do not think this is remotely worth a special case. The actual amount of overhead is not the key issue here: it's adding yet another logging technique to the codebase which people may imitate elsewhere.

Just make these logs compile-time controlled like ~all the other webview API logging: "if (DEBUG)" along with "private static final boolean DEBUG = false". People can build a webview with them turned on if they want then.
The big difference is that if user (developer, partner and other team) know and use it if WebView provides that feature, all party that involved in Android Autofill worked closely, and will be notified and use it immediately.

Since other places in WebView has been living without runtime log for a long time, then they might not actually need it.


Comment 18 by torne@chromium.org, Jun 19 2018

Michael: at minimum you need to update the current implementation so it doesn't introduce the issue mentioned in comment 2.

However, I would still prefer that you simply remove this logging.
Thanks torne, the runtime log is needed for autofill, I will provide the patch to fix the current issue, it is postponed because I don't want to offend you while we were discuss if this feature is needed or not.
Project Member

Comment 20 by bugdroid1@chromium.org, Jun 20 2018

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/8331585b3021c44ff0b2b5d038353247c31729c0

commit 8331585b3021c44ff0b2b5d038353247c31729c0
Author: Tao Bai <michaelbai@chromium.org>
Date: Wed Jun 20 05:37:56 2018

[WebView Autofill] Always check if log is enabled

Always check if log is enabled before ouput log, this avoid
creating string object while log is disabled.

Also only check Android log property when AwAutofillManager is
created or new session starts.

Bug:  843277 
Change-Id: Id2ab708646d434677d11016132cc47b6fa4985be
Reviewed-on: https://chromium-review.googlesource.com/1106959
Reviewed-by: Changwan Ryu <changwan@chromium.org>
Commit-Queue: Tao Bai <michaelbai@chromium.org>
Cr-Commit-Position: refs/heads/master@{#568736}
[modify] https://crrev.com/8331585b3021c44ff0b2b5d038353247c31729c0/android_webview/java/src/org/chromium/android_webview/AwAutofillManager.java
[modify] https://crrev.com/8331585b3021c44ff0b2b5d038353247c31729c0/android_webview/java/src/org/chromium/android_webview/AwAutofillProvider.java

Status: Fixed (was: Assigned)

Sign in to add a comment