1 /* 2 * Copyright 2014, The Android Open Source Project 3 * 4 * Licensed under the Apache License, Version 2.0 (the "License"); 5 * you may not use this file except in compliance with the License. 6 * You may obtain a copy of the License at 7 * 8 * http://www.apache.org/licenses/LICENSE-2.0 9 * 10 * Unless required by applicable law or agreed to in writing, software 11 * distributed under the License is distributed on an "AS IS" BASIS, 12 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. 13 * See the License for the specific language governing permissions and 14 * limitations under the License. 15 */ 16 17 package android.telecom; 18 19 import android.annotation.NonNull; 20 import android.compat.annotation.UnsupportedAppUsage; 21 import android.content.ComponentName; 22 import android.content.Context; 23 import android.net.Uri; 24 import android.os.Build; 25 import android.telecom.Logging.EventManager; 26 import android.telecom.Logging.Session; 27 import android.telecom.Logging.SessionManager; 28 import android.telephony.PhoneNumberUtils; 29 import android.text.TextUtils; 30 31 import com.android.internal.annotations.VisibleForTesting; 32 import com.android.internal.util.IndentingPrintWriter; 33 34 import java.util.Arrays; 35 import java.util.IllegalFormatException; 36 import java.util.Locale; 37 import java.util.stream.Collectors; 38 39 /** 40 * Manages logging for the entire module. 41 * 42 * @hide 43 */ 44 public class Log { 45 46 private static final long EXTENDED_LOGGING_DURATION_MILLIS = 60000 * 30; // 30 minutes 47 48 private static final int EVENTS_TO_CACHE = 10; 49 private static final int EVENTS_TO_CACHE_DEBUG = 20; 50 51 /** 52 * When generating a bug report, include the last X dialable digits when logging phone numbers. 53 */ 54 private static final int NUM_DIALABLE_DIGITS_TO_LOG = Build.IS_USER ? 0 : 2; 55 56 // Generic tag for all Telecom logging 57 @VisibleForTesting 58 public static String TAG = "TelecomFramework"; 59 public static boolean DEBUG = isLoggable(android.util.Log.DEBUG); 60 public static boolean INFO = isLoggable(android.util.Log.INFO); 61 public static boolean VERBOSE = isLoggable(android.util.Log.VERBOSE); 62 public static boolean WARN = isLoggable(android.util.Log.WARN); 63 public static boolean ERROR = isLoggable(android.util.Log.ERROR); 64 65 private static final boolean FORCE_LOGGING = false; /* STOP SHIP if true */ 66 private static final boolean USER_BUILD = Build.IS_USER; 67 68 // Used to synchronize singleton logging lazy initialization 69 private static final Object sSingletonSync = new Object(); 70 private static EventManager sEventManager; 71 private static volatile SessionManager sSessionManager; 72 private static Object sLock = null; 73 74 /** 75 * Tracks whether user-activated extended logging is enabled. 76 */ 77 private static boolean sIsUserExtendedLoggingEnabled = false; 78 79 /** 80 * Enabled in telecom testing to help gate log statements causing log spew. 81 */ 82 private static boolean sIsUnitTestingEnabled = false; 83 84 /** 85 * The time when user-activated extended logging should be ended. Used to determine when 86 * extended logging should automatically be disabled. 87 */ 88 private static long sUserExtendedLoggingStopTime = 0; 89 Log()90 private Log() { 91 } 92 d(String prefix, String format, Object... args)93 public static void d(String prefix, String format, Object... args) { 94 if (sIsUserExtendedLoggingEnabled) { 95 maybeDisableLogging(); 96 android.util.Slog.i(TAG, buildMessage(prefix, format, args)); 97 } else if (DEBUG) { 98 android.util.Slog.d(TAG, buildMessage(prefix, format, args)); 99 } 100 } 101 d(Object objectPrefix, String format, Object... args)102 public static void d(Object objectPrefix, String format, Object... args) { 103 if (sIsUserExtendedLoggingEnabled) { 104 maybeDisableLogging(); 105 android.util.Slog.i(TAG, buildMessage(getPrefixFromObject(objectPrefix), format, args)); 106 } else if (DEBUG) { 107 android.util.Slog.d(TAG, buildMessage(getPrefixFromObject(objectPrefix), format, args)); 108 } 109 } 110 111 @UnsupportedAppUsage(maxTargetSdk = Build.VERSION_CODES.R, trackingBug = 170729553) i(String prefix, String format, Object... args)112 public static void i(String prefix, String format, Object... args) { 113 if (INFO) { 114 android.util.Slog.i(TAG, buildMessage(prefix, format, args)); 115 } 116 } 117 i(Object objectPrefix, String format, Object... args)118 public static void i(Object objectPrefix, String format, Object... args) { 119 if (INFO) { 120 android.util.Slog.i(TAG, buildMessage(getPrefixFromObject(objectPrefix), format, args)); 121 } 122 } 123 v(String prefix, String format, Object... args)124 public static void v(String prefix, String format, Object... args) { 125 if (sIsUserExtendedLoggingEnabled) { 126 maybeDisableLogging(); 127 android.util.Slog.i(TAG, buildMessage(prefix, format, args)); 128 } else if (VERBOSE) { 129 android.util.Slog.v(TAG, buildMessage(prefix, format, args)); 130 } 131 } 132 v(Object objectPrefix, String format, Object... args)133 public static void v(Object objectPrefix, String format, Object... args) { 134 if (sIsUserExtendedLoggingEnabled) { 135 maybeDisableLogging(); 136 android.util.Slog.i(TAG, buildMessage(getPrefixFromObject(objectPrefix), format, args)); 137 } else if (VERBOSE) { 138 android.util.Slog.v(TAG, buildMessage(getPrefixFromObject(objectPrefix), format, args)); 139 } 140 } 141 142 @UnsupportedAppUsage(maxTargetSdk = Build.VERSION_CODES.R, trackingBug = 170729553) w(String prefix, String format, Object... args)143 public static void w(String prefix, String format, Object... args) { 144 if (WARN) { 145 android.util.Slog.w(TAG, buildMessage(prefix, format, args)); 146 } 147 } 148 w(Object objectPrefix, String format, Object... args)149 public static void w(Object objectPrefix, String format, Object... args) { 150 if (WARN) { 151 android.util.Slog.w(TAG, buildMessage(getPrefixFromObject(objectPrefix), format, args)); 152 } 153 } 154 e(String prefix, Throwable tr, String format, Object... args)155 public static void e(String prefix, Throwable tr, String format, Object... args) { 156 if (ERROR) { 157 android.util.Slog.e(TAG, buildMessage(prefix, format, args), tr); 158 } 159 } 160 e(Object objectPrefix, Throwable tr, String format, Object... args)161 public static void e(Object objectPrefix, Throwable tr, String format, Object... args) { 162 if (ERROR) { 163 android.util.Slog.e(TAG, buildMessage(getPrefixFromObject(objectPrefix), format, args), 164 tr); 165 } 166 } 167 wtf(String prefix, Throwable tr, String format, Object... args)168 public static void wtf(String prefix, Throwable tr, String format, Object... args) { 169 android.util.Slog.wtf(TAG, buildMessage(prefix, format, args), tr); 170 } 171 wtf(Object objectPrefix, Throwable tr, String format, Object... args)172 public static void wtf(Object objectPrefix, Throwable tr, String format, Object... args) { 173 android.util.Slog.wtf(TAG, buildMessage(getPrefixFromObject(objectPrefix), format, args), 174 tr); 175 } 176 wtf(String prefix, String format, Object... args)177 public static void wtf(String prefix, String format, Object... args) { 178 String msg = buildMessage(prefix, format, args); 179 android.util.Slog.wtf(TAG, msg, new IllegalStateException(msg)); 180 } 181 wtf(Object objectPrefix, String format, Object... args)182 public static void wtf(Object objectPrefix, String format, Object... args) { 183 String msg = buildMessage(getPrefixFromObject(objectPrefix), format, args); 184 android.util.Slog.wtf(TAG, msg, new IllegalStateException(msg)); 185 } 186 187 /** 188 * The ease of use methods below only act mostly as proxies to the Session and Event Loggers. 189 * They also control the lazy loaders of the singleton instances, which will never be loaded if 190 * the proxy methods aren't used. 191 * 192 * Please see each method's documentation inside of their respective implementations in the 193 * loggers. 194 */ 195 setSessionContext(Context context)196 public static void setSessionContext(Context context) { 197 getSessionManager().setContext(context); 198 } 199 startSession(String shortMethodName)200 public static void startSession(String shortMethodName) { 201 getSessionManager().startSession(shortMethodName, null); 202 } 203 startSession(Session.Info info, String shortMethodName)204 public static void startSession(Session.Info info, String shortMethodName) { 205 getSessionManager().startSession(info, shortMethodName, null); 206 } 207 startSession(String shortMethodName, String callerIdentification)208 public static void startSession(String shortMethodName, String callerIdentification) { 209 getSessionManager().startSession(shortMethodName, callerIdentification); 210 } 211 startSession(Session.Info info, String shortMethodName, String callerIdentification)212 public static void startSession(Session.Info info, String shortMethodName, 213 String callerIdentification) { 214 getSessionManager().startSession(info, shortMethodName, callerIdentification); 215 } 216 createSubsession()217 public static Session createSubsession() { 218 return getSessionManager().createSubsession(); 219 } 220 getExternalSession()221 public static Session.Info getExternalSession() { 222 return getSessionManager().getExternalSession(); 223 } 224 225 /** 226 * Retrieves external session information, providing a context for the recipient of the session 227 * info where the external session came from. 228 * @param ownerInfo The external owner info. 229 * @return New {@link Session.Info} instance with owner info set. 230 */ getExternalSession(@onNull String ownerInfo)231 public static Session.Info getExternalSession(@NonNull String ownerInfo) { 232 return getSessionManager().getExternalSession(ownerInfo); 233 } 234 cancelSubsession(Session subsession)235 public static void cancelSubsession(Session subsession) { 236 getSessionManager().cancelSubsession(subsession); 237 } 238 continueSession(Session subsession, String shortMethodName)239 public static void continueSession(Session subsession, String shortMethodName) { 240 getSessionManager().continueSession(subsession, shortMethodName); 241 } 242 endSession()243 public static void endSession() { 244 getSessionManager().endSession(); 245 } 246 registerSessionListener(SessionManager.ISessionListener l)247 public static void registerSessionListener(SessionManager.ISessionListener l) { 248 getSessionManager().registerSessionListener(l); 249 } 250 getSessionId()251 public static String getSessionId() { 252 // If the Session logger has not been initialized, then there have been no sessions logged. 253 // Don't load it now! 254 synchronized (sSingletonSync) { 255 if (sSessionManager != null) { 256 return getSessionManager().getSessionId(); 257 } else { 258 return ""; 259 } 260 } 261 } 262 addEvent(EventManager.Loggable recordEntry, String event)263 public static void addEvent(EventManager.Loggable recordEntry, String event) { 264 getEventManager().event(recordEntry, event, null); 265 } 266 addEvent(EventManager.Loggable recordEntry, String event, Object data)267 public static void addEvent(EventManager.Loggable recordEntry, String event, Object data) { 268 getEventManager().event(recordEntry, event, data); 269 } 270 addEvent(EventManager.Loggable recordEntry, String event, String format, Object... args)271 public static void addEvent(EventManager.Loggable recordEntry, String event, String format, 272 Object... args) { 273 getEventManager().event(recordEntry, event, format, args); 274 } 275 registerEventListener(EventManager.EventListener e)276 public static void registerEventListener(EventManager.EventListener e) { 277 getEventManager().registerEventListener(e); 278 } 279 addRequestResponsePair(EventManager.TimedEventPair p)280 public static void addRequestResponsePair(EventManager.TimedEventPair p) { 281 getEventManager().addRequestResponsePair(p); 282 } 283 dumpEvents(IndentingPrintWriter pw)284 public static void dumpEvents(IndentingPrintWriter pw) { 285 // If the Events logger has not been initialized, then there have been no events logged. 286 // Don't load it now! 287 synchronized (sSingletonSync) { 288 if (sEventManager != null) { 289 getEventManager().dumpEvents(pw); 290 } else { 291 pw.println("No Historical Events Logged."); 292 } 293 } 294 } 295 296 /** 297 * Dumps the events in a timeline format. 298 * @param pw The {@link IndentingPrintWriter} to write to. 299 * @hide 300 */ dumpEventsTimeline(IndentingPrintWriter pw)301 public static void dumpEventsTimeline(IndentingPrintWriter pw) { 302 // If the Events logger has not been initialized, then there have been no events logged. 303 // Don't load it now! 304 synchronized (sSingletonSync) { 305 if (sEventManager != null) { 306 getEventManager().dumpEventsTimeline(pw); 307 } else { 308 pw.println("No Historical Events Logged."); 309 } 310 } 311 } 312 313 /** 314 * Enable or disable extended telecom logging. 315 * 316 * @param isExtendedLoggingEnabled {@code true} if extended logging should be enabled, 317 * {@code false} if it should be disabled. 318 */ setIsExtendedLoggingEnabled(boolean isExtendedLoggingEnabled)319 public static void setIsExtendedLoggingEnabled(boolean isExtendedLoggingEnabled) { 320 // If the state hasn't changed, bail early. 321 if (sIsUserExtendedLoggingEnabled == isExtendedLoggingEnabled) { 322 return; 323 } 324 325 if (sEventManager != null) { 326 sEventManager.changeEventCacheSize(isExtendedLoggingEnabled ? 327 EVENTS_TO_CACHE_DEBUG : EVENTS_TO_CACHE); 328 } 329 330 sIsUserExtendedLoggingEnabled = isExtendedLoggingEnabled; 331 if (sIsUserExtendedLoggingEnabled) { 332 sUserExtendedLoggingStopTime = System.currentTimeMillis() 333 + EXTENDED_LOGGING_DURATION_MILLIS; 334 } else { 335 sUserExtendedLoggingStopTime = 0; 336 } 337 } 338 339 /** 340 * Enabled when tests are running to help gate log statements causing log spew. 341 * 342 * @param isEnabled {@code true} if running unit tests. false otherwise. 343 * 344 */ setUnitTestingEnabled(boolean isEnabled)345 public static void setUnitTestingEnabled(boolean isEnabled) { 346 sIsUnitTestingEnabled = isEnabled; 347 } 348 isUnitTestingEnabled()349 public static boolean isUnitTestingEnabled() { 350 return sIsUnitTestingEnabled; 351 } 352 getEventManager()353 private static EventManager getEventManager() { 354 // Checking for null again outside of synchronization because we only need to synchronize 355 // during the lazy loading of the events logger. We don't need to synchronize elsewhere. 356 if (sEventManager == null) { 357 synchronized (sSingletonSync) { 358 if (sEventManager == null) { 359 sEventManager = new EventManager(Log::getSessionId); 360 return sEventManager; 361 } 362 } 363 } 364 return sEventManager; 365 } 366 367 @VisibleForTesting getSessionManager()368 public static SessionManager getSessionManager() { 369 // Checking for null again outside of synchronization because we only need to synchronize 370 // during the lazy loading of the session logger. We don't need to synchronize elsewhere. 371 if (sSessionManager == null) { 372 synchronized (sSingletonSync) { 373 if (sSessionManager == null) { 374 sSessionManager = new SessionManager(); 375 return sSessionManager; 376 } 377 } 378 } 379 return sSessionManager; 380 } 381 382 @VisibleForTesting setSessionManager(Context context, java.lang.Runnable cleanSessionRunnable)383 public static SessionManager setSessionManager(Context context, 384 java.lang.Runnable cleanSessionRunnable) { 385 // Checking for null again outside of synchronization because we only need to synchronize 386 // during the lazy loading of the session logger. We don't need to synchronize elsewhere. 387 if (sSessionManager == null) { 388 synchronized (sSingletonSync) { 389 if (sSessionManager == null) { 390 sSessionManager = new SessionManager(cleanSessionRunnable); 391 sSessionManager.setContext(context); 392 return sSessionManager; 393 } 394 } 395 } 396 return sSessionManager; 397 } 398 setTag(String tag)399 public static void setTag(String tag) { 400 TAG = tag; 401 DEBUG = isLoggable(android.util.Log.DEBUG); 402 INFO = isLoggable(android.util.Log.INFO); 403 VERBOSE = isLoggable(android.util.Log.VERBOSE); 404 WARN = isLoggable(android.util.Log.WARN); 405 ERROR = isLoggable(android.util.Log.ERROR); 406 } 407 408 /** 409 * Sets the main telecom sync lock used within Telecom. This is used when building log messages 410 * so that we can identify places in the code where we are doing something outside of the 411 * Telecom lock. 412 * @param lock The lock. 413 */ setLock(Object lock)414 public static void setLock(Object lock) { 415 // Don't do lock monitoring on user builds. 416 if (!Build.IS_USER) { 417 sLock = lock; 418 } 419 } 420 421 /** 422 * If user enabled extended logging is enabled and the time limit has passed, disables the 423 * extended logging. 424 */ maybeDisableLogging()425 private static void maybeDisableLogging() { 426 if (!sIsUserExtendedLoggingEnabled) { 427 return; 428 } 429 430 if (sUserExtendedLoggingStopTime < System.currentTimeMillis()) { 431 sUserExtendedLoggingStopTime = 0; 432 sIsUserExtendedLoggingEnabled = false; 433 } 434 } 435 isLoggable(int level)436 public static boolean isLoggable(int level) { 437 return FORCE_LOGGING || android.util.Log.isLoggable(TAG, level); 438 } 439 440 /** 441 * Generates an obfuscated string for a calling handle in {@link Uri} format, or a raw phone 442 * phone number in {@link String} format. 443 * @param pii The information to obfuscate. 444 * @return The obfuscated string. 445 */ piiHandle(Object pii)446 public static String piiHandle(Object pii) { 447 if (pii == null || VERBOSE) { 448 return String.valueOf(pii); 449 } 450 451 StringBuilder sb = new StringBuilder(); 452 if (pii instanceof Uri) { 453 Uri uri = (Uri) pii; 454 String scheme = uri.getScheme(); 455 456 if (!TextUtils.isEmpty(scheme)) { 457 sb.append(scheme).append(":"); 458 } 459 460 String textToObfuscate = uri.getSchemeSpecificPart(); 461 if (PhoneAccount.SCHEME_TEL.equals(scheme)) { 462 obfuscatePhoneNumber(sb, textToObfuscate); 463 } else if (PhoneAccount.SCHEME_SIP.equals(scheme)) { 464 for (int i = 0; i < textToObfuscate.length(); i++) { 465 char c = textToObfuscate.charAt(i); 466 if (c != '@' && c != '.') { 467 c = '*'; 468 } 469 sb.append(c); 470 } 471 } else { 472 sb.append(pii(pii)); 473 } 474 } else if (pii instanceof String) { 475 String number = (String) pii; 476 obfuscatePhoneNumber(sb, number); 477 } 478 479 return sb.toString(); 480 } 481 482 /** 483 * Obfuscates a phone number, allowing NUM_DIALABLE_DIGITS_TO_LOG digits to be exposed for the 484 * phone number. 485 * @param sb String buffer to write obfuscated number to. 486 * @param phoneNumber The number to obfuscate. 487 */ obfuscatePhoneNumber(StringBuilder sb, String phoneNumber)488 private static void obfuscatePhoneNumber(StringBuilder sb, String phoneNumber) { 489 int numDigitsToObfuscate = getDialableCount(phoneNumber) 490 - NUM_DIALABLE_DIGITS_TO_LOG; 491 for (int i = 0; i < phoneNumber.length(); i++) { 492 char c = phoneNumber.charAt(i); 493 boolean isDialable = PhoneNumberUtils.isDialable(c); 494 if (isDialable) { 495 numDigitsToObfuscate--; 496 } 497 sb.append(isDialable && numDigitsToObfuscate >= 0 ? "*" : c); 498 } 499 } 500 501 /** 502 * Determines the number of dialable characters in a string. 503 * @param toCount The string to count dialable characters in. 504 * @return The count of dialable characters. 505 */ getDialableCount(String toCount)506 private static int getDialableCount(String toCount) { 507 int numDialable = 0; 508 for (char c : toCount.toCharArray()) { 509 if (PhoneNumberUtils.isDialable(c)) { 510 numDialable++; 511 } 512 } 513 return numDialable; 514 } 515 516 /** 517 * Redact personally identifiable information for production users. 518 * If we are running in verbose mode, return the original string, 519 * and return "***" otherwise. 520 */ pii(Object pii)521 public static String pii(Object pii) { 522 if (pii == null || VERBOSE) { 523 return String.valueOf(pii); 524 } 525 return "***"; 526 } 527 getPrefixFromObject(Object obj)528 private static String getPrefixFromObject(Object obj) { 529 return obj == null ? "<null>" : obj.getClass().getSimpleName(); 530 } 531 buildMessage(String prefix, String format, Object... args)532 private static String buildMessage(String prefix, String format, Object... args) { 533 // Incorporate thread ID and calling method into prefix 534 String sessionName = getSessionId(); 535 String sessionPostfix = TextUtils.isEmpty(sessionName) ? "" : ": " + sessionName; 536 537 String msg; 538 try { 539 msg = (args == null || args.length == 0) ? format 540 : String.format(Locale.US, format, args); 541 } catch (IllegalFormatException ife) { 542 e(TAG, ife, "Log: IllegalFormatException: formatString='%s' numArgs=%d", format, 543 args.length); 544 msg = format + " (An error occurred while formatting the message.)"; 545 } 546 // If a lock was set, check if this thread holds that lock and output an emoji that lets 547 // the developer know whether a log message came from within the Telecom lock or not. 548 String isLocked = sLock != null ? (Thread.holdsLock(sLock) ? "\uD83D\uDD12" : "❗") : ""; 549 return String.format(Locale.US, "%s: %s%s%s", prefix, msg, sessionPostfix, isLocked); 550 } 551 552 /** 553 * Generates an abbreviated version of the package name from a component. 554 * E.g. com.android.phone becomes cap 555 * @param componentName The component name to abbreviate. 556 * @return Abbreviation of empty string if component is null. 557 * @hide 558 */ getPackageAbbreviation(ComponentName componentName)559 public static String getPackageAbbreviation(ComponentName componentName) { 560 if (componentName == null) { 561 return ""; 562 } 563 return getPackageAbbreviation(componentName.getPackageName()); 564 } 565 566 /** 567 * Generates an abbreviated version of the package name. 568 * E.g. com.android.phone becomes cap 569 * @param packageName The packageName name to abbreviate. 570 * @return Abbreviation of empty string if package is null. 571 * @hide 572 */ getPackageAbbreviation(String packageName)573 public static String getPackageAbbreviation(String packageName) { 574 if (packageName == null) { 575 return ""; 576 } 577 return Arrays.stream(packageName.split("\\.")) 578 .map(s -> s.length() == 0 ? "" : s.substring(0, 1)) 579 .collect(Collectors.joining("")); 580 } 581 } 582