Chromium Code Reviews
chromiumcodereview-hr@appspot.gserviceaccount.com (chromiumcodereview-hr) | Please choose your nickname with Settings | Help | Chromium Project | Gerrit Changes | Sign out
(265)

Side by Side Diff: docs/android_logging.md

Issue 1324943003: Move the android logging doc to //docs (Closed) Base URL: https://chromium.googlesource.com/chromium/src.git@master
Patch Set: Updated ref to the doc in the java class Created 5 years, 3 months ago
Use n/p to move between diff chunks; N/P to move between comments. Draft comments are only viewable by you.
Jump to:
View unified diff | Download patch
« no previous file with comments | « base/android/java/src/org/chromium/base/README_logging.md ('k') | no next file » | no next file with comments »
Toggle Intra-line Diffs ('i') | Expand Comments ('e') | Collapse Comments ('c') | Show Comments Hide Comments ('s')
OLDNEW
1 ## Logging ## 1 # Logging #
2 2
3 [TOC]
4
5
6 ## Overview
7
3 Logging used to be done using Android's [android.util.Log] 8 Logging used to be done using Android's [android.util.Log]
4 (http://developer.android.com/reference/android/util/Log.html). 9 (http://developer.android.com/reference/android/util/Log.html).
5 10
6 A wrapper on that is now available: org.chromium.base.Log. It is designed to wri te logs as 11 A wrapper on that is now available: org.chromium.base.Log. It is designed to
7 belonging to logical groups going beyond single classes, and to make it easy to switch logging on 12 write logs as belonging to logical groups going beyond single classes, and to
8 or off for individual groups. 13 make it easy to switch logging on or off for individual groups.
9 14
10 Usage: 15 Usage:
11 16
12 private static final String TAG = "cr.YourModuleTag"; 17 ```java
13 ... 18 private static final String TAG = "cr.YourModuleTag";
14 Log.i(TAG, "Logged INFO message."); 19 ...
15 Log.d(TAG, "Some DEBUG info: %s", data); 20 Log.i(TAG, "Logged INFO message.");
21 Log.d(TAG, "Some DEBUG info: %s", data);
22 ```
16 23
17 Output: 24 Output:
18 25
19 I/cr.YourModuleTag: ( 999): Logged INFO message 26 ```
20 D/cr.YourModuleTag: ( 999): [MyClass.java:42] Some DEBUG info: data's toStri ng output 27 I/cr.YourModuleTag: ( 999): Logged INFO message
28 D/cr.YourModuleTag: ( 999): [MyClass.java:42] Some DEBUG info: data.toString
29 ```
21 30
22 Here, **TAG** will be a feature or package name, "MediaRemote" or "NFC" for exam ple. In most 31 Here, **TAG** will be a feature or package name, "MediaRemote" or "NFC" for
23 cases, the class name is not needed. 32 example. In most cases, the class name is not needed.
24 33
25 ### Verbose and Debug logs have special handling ### 34 ### Verbose and Debug logs have special handling ###
26 35
27 * `Log.v` and `Log.d` Calls made using `org.chromium.base.Log` are stripped 36 * `Log.v` and `Log.d` Calls made using `org.chromium.base.Log` are stripped
28 out of production binaries using Proguard. There is no way to get those logs 37 out of production binaries using Proguard. There is no way to get those logs
29 in release builds. 38 in release builds.
30 39
31 * The file name and line number will be prepended to the log message. 40 * The file name and line number will be prepended to the log message.
32 For higher priority logs, those are not added for performance concerns. 41 For higher priority logs, those are not added for performance concerns.
33 42
34 ### An exception trace is printed when the exception is the last parameter ### 43 ### An exception trace is printed when the exception is the last parameter ###
35 44
36 As with `java.util.Log`, putting a throwable as last parameter will dump the cor responding stack 45 As with `java.util.Log`, putting a throwable as last parameter will dump the
37 trace: 46 corresponding stack trace:
38 47
39 Log.i(TAG, "An error happened: %s", e) 48 ```java
49 Log.i(TAG, "An error happened: %s", e)
50 ```
40 51
41 I/cr.YourModuleTag: ( 999): An error happened: This is the exception's messa ge 52 ```
42 I/cr.YourModuleTag: ( 999): java.lang.Exception: This is the exception's mes sage 53 I/cr.YourModuleTag: ( 999): An error happened: This is the exception's message
43 I/cr.YourModuleTag: ( 999): at foo.bar.MyClass.test(MyClass.java:42) 54 I/cr.YourModuleTag: ( 999): java.lang.Exception: This is the exception's message
44 I/cr.YourModuleTag: ( 999): ... 55 I/cr.YourModuleTag: ( 999): at foo.bar.MyClass.test(MyClass.java:42)
56 I/cr.YourModuleTag: ( 999): ...
57 ```
45 58
46 Having the exception as last parameter doesn't prevent it from being used for st ring formatting. 59 Having the exception as last parameter doesn't prevent it from being used for
60 string formatting.
47 61
48 ### Logging Best Practices 62 ## Logging Best Practices
49 63
50 #### Rule #1: Never log PII (Personal Identification Information): 64 ### Rule #1: Never log PII (Personal Identification Information):
51 65
52 This is a huge concern, because other applications can access the log and extrac t a lot of data 66 This is a huge concern, because other applications can access the log and
53 from your own by doing so. Even if JellyBean restricted this, people are going t o run your 67 extract a lot of data from your own by doing so. Even if JellyBean restricted
54 application on rooted devices and allow some apps to access it. Also anyone with USB access to the 68 this, people are going to run your application on rooted devices and allow some
55 device can use ADB to get the full logcat and get the same data right now. 69 apps to access it. Also anyone with USB access to the device can use ADB to get
70 the full logcat and get the same data right now.
56 71
57 If you really need to print something , print a series of Xs instead (e.g. "XXXX XX"), or print a 72 If you really need to print something , print a series of Xs instead
58 truncated hash of the PII instead. Truncation is required to make it harder for an attacker to 73 (e.g. "XXXXXX"), or print a truncated hash of the PII instead. Truncation is
59 recover the full data through rainbow tables and similar methods. 74 required to make it harder for an attacker to recover the full data through
75 rainbow tables and similar methods.
60 76
61 Similarly, avoid dumping API keys, cookies, etc... 77 Similarly, avoid dumping API keys, cookies, etc...
62 78
63 #### Rule #2: Do not build debug logs in production code: 79 ### Rule #2: Do not build debug logs in production code:
64 80
65 The log methods are removed in release builds using Proguard. Because log messag es might not be 81 The log methods are removed in release builds using Proguard. Because log
66 written, the cost of creating them should also be avoided. This can be done usin g three 82 messages might not be written, the cost of creating them should also be avoided.
67 complementary ways: 83 This can be done using three complementary ways:
68 84
69 - Use string formatting instead of concatenations 85 #### Use string formatting instead of concatenations
70 86
71 // BAD 87 ```java
72 Log.d(TAG, "I " + preference + " writing logs."); 88 // BAD
89 Log.d(TAG, "I " + preference + " writing logs.");
73 90
74 // BETTER 91 // BETTER
75 Log.d(TAG, "I %s writing logs.", preference); 92 Log.d(TAG, "I %s writing logs.", preference);
93 ```
76 94
77 Proguard removes the method call itself, but doesn't do anything about the a rguments. The 95 Proguard removes the method call itself, but doesn't do anything about the
78 method's arguments will still be computed and provided as input. The first c all above will 96 arguments. The method's arguments will still be computed and provided as
79 always lead to the creation of a `StringBuilder` and a few concatenations, w hile the second just 97 input. The first call above will always lead to the creation of a
80 passes the arguments and won't need that. 98 `StringBuilder` and a few concatenations, while the second just passes the
99 arguments and won't need that.
81 100
82 - Guard expensive calls 101 #### Guard expensive calls
83 102
84 Sometimes the values to log aren't readily available and need to be computed specially. This 103 Sometimes the values to log aren't readily available and need to be computed
85 should be avoided when logging is disabled. 104 specially. This should be avoided when logging is disabled.
86 105
87 static private final boolean DEBUG = false; // set to 'true' to enable debug 106 ```java
88 ... 107 static private final boolean DEBUG = false; // debug toggle.
89 if (DEBUG) { 108 ...
90 Log.i(TAG, createThatExpensiveLogMessage(activity)) 109 if (DEBUG) {
91 } 110 Log.i(TAG, createThatExpensiveLogMessage(activity))
111 }
112 ```
92 113
93 Because the variable is a `static final` that can be evaluated at compile ti me, the Java 114 Because the variable is a `static final` that can be evaluated at compile
94 compiler will optimize out all guarded calls from the generated `.class` fil e. Changing it 115 time, the Java compiler will optimize out all guarded calls from the
95 however requires editing each of the files for which debug should be enabled and recompiling. 116 generated `.class` file. Changing it however requires editing each of the
117 files for which debug should be enabled and recompiling.
96 118
97 - Annotate debug functions with the `@RemovableInRelease` annotation. 119 #### Annotate debug functions with the `@RemovableInRelease` annotation.
98 120
99 That annotation tells Proguard to assume that a given function has no side e ffects, and is 121 That annotation tells Proguard to assume that a given function has no side
100 called only for its returned value. If this value is unused, the call will b e removed. If the 122 effects, and is called only for its returned value. If this value is unused,
101 function is not called at all, it will also be removed. Since Proguard is al ready used to 123 the call will be removed. If the function is not called at all, it will also
102 strip debug and verbose calls out of release builds, this annotation allows it to have a 124 be removed. Since Proguard is already used to strip debug and verbose calls
103 deeper action by removing also function calls used to generate the log call' s arguments. 125 out of release builds, this annotation allows it to have a deeper action by
126 removing also function calls used to generate the log call's arguments.
104 127
105 /* If that function is only used in Log.d calls, proguard should complet ely remove it from 128 ```java
106 * the release builds. */ 129 /* If that function is only used in Log.d calls, proguard should
107 @RemovableInRelease 130 * completely remove it from the release builds. */
108 private static String getSomeDebugLogString(Thing[] things) { 131 @RemovableInRelease
109 StringBuilder sb = new StringBuilder("Reporting " + thing.length + " t hings:"); 132 private static String getSomeDebugLogString(Thing[] things) {
110 for (Thing thing : things) { 133 StringBuilder sb = new StringBuilder(
111 sb.append('\n').append(thing.id).append(' ').append(report.foo); 134 "Reporting " + thing.length + " things: ");
112 } 135 for (Thing thing : things) {
113 return sb.toString(); 136 sb.append('\n').append(thing.id).append(' ').append(report.foo);
114 } 137 }
138 return sb.toString();
139 }
115 140
116 public void bar() { 141 public void bar() {
117 ... 142 ...
118 Log.d(TAG, getSomeDebugLogString(things)); /* The line is removed in r elease builds. */ 143 Log.d(TAG, getSomeDebugLogString(things)); /* The line is removed in
119 } 144 * release builds. */
145 }
146 ```
120 147
121 Again, this is useful only if the input to that function are variables alrea dy available in 148 Again, this is useful only if the input to that function are variables
122 the scope. The idea is to move computations, concatenations, etc. to a place where that can be 149 already available in the scope. The idea is to move computations,
123 removed when not needed, without invading the main function's logic. It can then have a similar 150 concatenations, etc. to a place where that can be removed when not needed,
124 effect as guarding with a static final property that would be enabled in Deb ug and disabled in 151 without invading the main function's logic. It can then have a similar
125 Release. 152 effect as guarding with a static final property that would be enabled in
153 Debug and disabled in Release.
126 154
127 #### Rule #3: Favor small log messages 155 ### Rule #3: Favor small log messages
128 156
129 This is still related to the global fixed-sized kernel buffer used to keep all l ogs. Try to make 157 This is still related to the global fixed-sized kernel buffer used to keep all
130 your log information as terse as possible. This reduces the risk of pushing inte resting log data 158 logs. Try to make your log information as terse as possible. This reduces the
131 out of the buffer when something really nasty happens. It's really better to hav e a single-line 159 risk of pushing interesting log data out of the buffer when something really
132 log message, than several ones. I.e. don't use: 160 nasty happens. It's really better to have a single-line log message, than
161 several ones. I.e. don't use:
133 162
134 Log.GROUP.d(TAG, "field1 = %s", value1); 163 ```java
135 Log.GROUP.d(TAG, "field2 = %s", value2); 164 Log.GROUP.d(TAG, "field1 = %s", value1);
136 Log.GROUP.d(TAG, "field3 = %s", value3); 165 Log.GROUP.d(TAG, "field2 = %s", value2);
166 Log.GROUP.d(TAG, "field3 = %s", value3);
167 ```
137 168
138 Instead, write this as: 169 Instead, write this as:
139 170
140 Log.d(TAG, "field1 = %s, field2 = %s, field3 = %s", value1, value2, value3); 171 ```java
172 Log.d(TAG, "field1 = %s, field2 = %s, field3 = %s", value1, value2, value3);
173 ```
141 174
142 That doesn't seem to be much different if you count overall character counts, bu t each independent 175 That doesn't seem to be much different if you count overall character counts,
143 log entry also implies a small, but non-trivial header, in the kernel log buffer . 176 but each independent log entry also implies a small, but non-trivial header, in
144 And since every byte count, you can also try something even shorter, as in: 177 the kernel log buffer. And since every byte count, you can also try something
178 even shorter, as in:
145 179
146 Log.d(TAG, "fields [%s,%s,%s]", value1, value2, value3); 180 ```java
181 Log.d(TAG, "fields [%s,%s,%s]", value1, value2, value3);
182 ```
147 183
148 ### Filtering logs 184 ## Filtering logs
149 185
150 Logcat allows filtering by specifying tags and the associated level: 186 Logcat allows filtering by specifying tags and the associated level:
151 187
152 adb logcat [TAG_EXPR:LEVEL]... 188 ```shell
153 adb logcat cr.YourModuleTag:D *:S 189 adb logcat [TAG_EXPR:LEVEL]...
190 adb logcat cr.YourModuleTag:D *:S
191 ```
154 192
155 This shows only logs having a level higher or equal to DEBUG for `cr.YourModuleT ag`, and SILENT 193 This shows only logs having a level higher or equal to DEBUG for
156 (nothing is logged at this level or higher, so it silences the tags) for everyth ing else. You can 194 `cr.YourModuleTag`, and SILENT (nothing is logged at this level or higher, so it
157 persist a filter by setting an environment variable: 195 silences the tags) for everything else. You can persist a filter by setting an
196 environment variable:
158 197
159 export ANDROID_LOG_TAGS="cr.YourModuleTag:D *:S" 198 ```shell
199 export ANDROID_LOG_TAGS="cr.YourModuleTag:D *:S"
200 ```
160 201
161 For more, see the [related page on developer.android.com] 202 For more, see the [related page on developer.android.com]
162 (http://developer.android.com/tools/debugging/debugging-log.html#filteringOutput ) 203 (http://developer.android.com/tools/debugging/debugging-log.html#filteringOutput )
OLDNEW
« no previous file with comments | « base/android/java/src/org/chromium/base/README_logging.md ('k') | no next file » | no next file with comments »

Powered by Google App Engine
This is Rietveld 408576698