1 /* 2 * Copyright (C) 2024 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 com.android.internal.protolog; 18 19 import static android.content.Context.PROTOLOG_CONFIGURATION_SERVICE; 20 import static android.internal.perfetto.protos.InternedDataOuterClass.InternedData.PROTOLOG_STACKTRACE; 21 import static android.internal.perfetto.protos.InternedDataOuterClass.InternedData.PROTOLOG_STRING_ARGS; 22 import static android.internal.perfetto.protos.ProfileCommon.InternedString.IID; 23 import static android.internal.perfetto.protos.ProfileCommon.InternedString.STR; 24 import static android.internal.perfetto.protos.Protolog.ProtoLogMessage.BOOLEAN_PARAMS; 25 import static android.internal.perfetto.protos.Protolog.ProtoLogMessage.DOUBLE_PARAMS; 26 import static android.internal.perfetto.protos.Protolog.ProtoLogMessage.MESSAGE_ID; 27 import static android.internal.perfetto.protos.Protolog.ProtoLogMessage.SINT64_PARAMS; 28 import static android.internal.perfetto.protos.Protolog.ProtoLogMessage.STACKTRACE_IID; 29 import static android.internal.perfetto.protos.Protolog.ProtoLogMessage.STR_PARAM_IIDS; 30 import static android.internal.perfetto.protos.Protolog.ProtoLogViewerConfig.GROUPS; 31 import static android.internal.perfetto.protos.Protolog.ProtoLogViewerConfig.Group.ID; 32 import static android.internal.perfetto.protos.Protolog.ProtoLogViewerConfig.Group.NAME; 33 import static android.internal.perfetto.protos.Protolog.ProtoLogViewerConfig.Group.TAG; 34 import static android.internal.perfetto.protos.Protolog.ProtoLogViewerConfig.MESSAGES; 35 import static android.internal.perfetto.protos.Protolog.ProtoLogViewerConfig.MessageData.GROUP_ID; 36 import static android.internal.perfetto.protos.Protolog.ProtoLogViewerConfig.MessageData.LEVEL; 37 import static android.internal.perfetto.protos.Protolog.ProtoLogViewerConfig.MessageData.MESSAGE; 38 import static android.internal.perfetto.protos.TracePacketOuterClass.TracePacket.INTERNED_DATA; 39 import static android.internal.perfetto.protos.TracePacketOuterClass.TracePacket.PROTOLOG_MESSAGE; 40 import static android.internal.perfetto.protos.TracePacketOuterClass.TracePacket.PROTOLOG_VIEWER_CONFIG; 41 import static android.internal.perfetto.protos.TracePacketOuterClass.TracePacket.SEQUENCE_FLAGS; 42 import static android.internal.perfetto.protos.TracePacketOuterClass.TracePacket.SEQ_INCREMENTAL_STATE_CLEARED; 43 import static android.internal.perfetto.protos.TracePacketOuterClass.TracePacket.SEQ_NEEDS_INCREMENTAL_STATE; 44 import static android.internal.perfetto.protos.TracePacketOuterClass.TracePacket.TIMESTAMP; 45 46 import android.annotation.NonNull; 47 import android.annotation.Nullable; 48 import android.internal.perfetto.protos.Protolog.ProtoLogViewerConfig.MessageData; 49 import android.os.RemoteException; 50 import android.os.ServiceManager; 51 import android.os.ShellCommand; 52 import android.os.SystemClock; 53 import android.text.TextUtils; 54 import android.tracing.perfetto.InitArguments; 55 import android.tracing.perfetto.Producer; 56 import android.tracing.perfetto.TracingContext; 57 import android.util.ArrayMap; 58 import android.util.ArraySet; 59 import android.util.Log; 60 import android.util.LongArray; 61 import android.util.Slog; 62 import android.util.proto.ProtoOutputStream; 63 64 import com.android.internal.annotations.VisibleForTesting; 65 import com.android.internal.protolog.IProtoLogConfigurationService.RegisterClientArgs; 66 import com.android.internal.protolog.common.ILogger; 67 import com.android.internal.protolog.common.IProtoLog; 68 import com.android.internal.protolog.common.IProtoLogGroup; 69 import com.android.internal.protolog.common.InvalidFormatStringException; 70 import com.android.internal.protolog.common.LogDataType; 71 import com.android.internal.protolog.common.LogLevel; 72 73 import java.io.PrintWriter; 74 import java.io.StringWriter; 75 import java.util.ArrayList; 76 import java.util.Arrays; 77 import java.util.List; 78 import java.util.Map; 79 import java.util.Objects; 80 import java.util.Set; 81 import java.util.TreeMap; 82 import java.util.UUID; 83 import java.util.concurrent.ExecutionException; 84 import java.util.concurrent.ExecutorService; 85 import java.util.concurrent.Executors; 86 import java.util.concurrent.TimeUnit; 87 import java.util.concurrent.atomic.AtomicInteger; 88 import java.util.concurrent.locks.Lock; 89 import java.util.concurrent.locks.ReentrantLock; 90 91 /** 92 * A service for the ProtoLog logging system. 93 */ 94 public abstract class PerfettoProtoLogImpl extends IProtoLogClient.Stub implements IProtoLog { 95 private static final String LOG_TAG = "ProtoLog"; 96 public static final String NULL_STRING = "null"; 97 private final AtomicInteger mTracingInstances = new AtomicInteger(); 98 99 @NonNull 100 protected final ProtoLogDataSource mDataSource; 101 @Nullable 102 protected final IProtoLogConfigurationService mConfigurationService; 103 @NonNull 104 protected final TreeMap<String, IProtoLogGroup> mLogGroups = new TreeMap<>(); 105 @NonNull 106 private final ProtoLogCacheUpdater mCacheUpdater; 107 108 @NonNull 109 private final int[] mDefaultLogLevelCounts = new int[LogLevel.values().length]; 110 @NonNull 111 private final Map<String, int[]> mLogLevelCounts = new ArrayMap<>(); 112 @NonNull 113 private final Map<String, Integer> mCollectStackTraceGroupCounts = new ArrayMap<>(); 114 115 private final Lock mBackgroundServiceLock = new ReentrantLock(); 116 protected ExecutorService mBackgroundLoggingService = Executors.newSingleThreadExecutor(); 117 118 // Set to true once this is ready to accept protolog to logcat requests. 119 private boolean mLogcatReady = false; 120 PerfettoProtoLogImpl( @onNull ProtoLogDataSource dataSource, @NonNull ProtoLogCacheUpdater cacheUpdater, @NonNull IProtoLogGroup[] groups)121 protected PerfettoProtoLogImpl( 122 @NonNull ProtoLogDataSource dataSource, 123 @NonNull ProtoLogCacheUpdater cacheUpdater, 124 @NonNull IProtoLogGroup[] groups) throws ServiceManager.ServiceNotFoundException { 125 this(dataSource, cacheUpdater, groups, 126 android.tracing.Flags.clientSideProtoLogging() ? 127 IProtoLogConfigurationService.Stub.asInterface( 128 ServiceManager.getServiceOrThrow(PROTOLOG_CONFIGURATION_SERVICE) 129 ) : null 130 ); 131 } 132 PerfettoProtoLogImpl( @onNull ProtoLogDataSource dataSource, @NonNull ProtoLogCacheUpdater cacheUpdater, @NonNull IProtoLogGroup[] groups, @Nullable IProtoLogConfigurationService configurationService)133 protected PerfettoProtoLogImpl( 134 @NonNull ProtoLogDataSource dataSource, 135 @NonNull ProtoLogCacheUpdater cacheUpdater, 136 @NonNull IProtoLogGroup[] groups, 137 @Nullable IProtoLogConfigurationService configurationService) { 138 mDataSource = dataSource; 139 mCacheUpdater = cacheUpdater; 140 mConfigurationService = configurationService; 141 142 registerGroupsLocally(groups); 143 } 144 145 /** 146 * To be called to enable the ProtoLogImpl to start tracing to ProtoLog and register with all 147 * the expected ProtoLog components. 148 */ enable()149 public void enable() { 150 Producer.init(InitArguments.DEFAULTS); 151 152 if (android.tracing.Flags.clientSideProtoLogging()) { 153 connectToConfigurationService(); 154 } 155 156 mDataSource.registerOnStartCallback(this::onTracingInstanceStart); 157 mDataSource.registerOnFlushCallback(this::onTracingFlush); 158 mDataSource.registerOnStopCallback(this::onTracingInstanceStop); 159 } 160 connectToConfigurationService()161 private void connectToConfigurationService() { 162 Objects.requireNonNull(mConfigurationService, 163 "A null ProtoLog Configuration Service was provided!"); 164 165 mBackgroundLoggingService.execute(() -> { 166 try { 167 var args = createConfigurationServiceRegisterClientArgs(); 168 169 args.groups = new String[mLogGroups.size()]; 170 args.groupsDefaultLogcatStatus = new boolean[mLogGroups.size()]; 171 172 var groups = mLogGroups.values().stream().toList(); 173 for (var i = 0; i < groups.size(); i++) { 174 var group = groups.get(i); 175 args.groups[i] = group.name(); 176 args.groupsDefaultLogcatStatus[i] = group.isLogToLogcat(); 177 } 178 179 mConfigurationService.registerClient(this, args); 180 } catch (RemoteException e) { 181 throw new RuntimeException("Failed to register ProtoLog client"); 182 } 183 }); 184 } 185 186 /** 187 * Should be called when we no longer want to use the ProtoLog logger to unlink ourselves from 188 * the datasource and the configuration service to ensure we no longer receive the callback. 189 */ disable()190 public void disable() { 191 mDataSource.unregisterOnStartCallback(this::onTracingInstanceStart); 192 mDataSource.unregisterOnFlushCallback(this::onTracingFlush); 193 mDataSource.unregisterOnStopCallback(this::onTracingInstanceStop); 194 } 195 196 @NonNull createConfigurationServiceRegisterClientArgs()197 protected abstract RegisterClientArgs createConfigurationServiceRegisterClientArgs(); 198 199 /** 200 * Main log method, do not call directly. 201 */ 202 @VisibleForTesting 203 @Override log(LogLevel logLevel, IProtoLogGroup group, long messageHash, int paramsMask, @Nullable Object[] args)204 public void log(LogLevel logLevel, IProtoLogGroup group, long messageHash, int paramsMask, 205 @Nullable Object[] args) { 206 log(logLevel, group, new Message(messageHash, paramsMask), args); 207 } 208 209 @Override log(LogLevel logLevel, IProtoLogGroup group, String messageString, Object... args)210 public void log(LogLevel logLevel, IProtoLogGroup group, String messageString, Object... args) { 211 try { 212 log(logLevel, group, new Message(messageString), args); 213 } catch (InvalidFormatStringException e) { 214 Slog.e(LOG_TAG, "Invalid protolog string format", e); 215 log(logLevel, group, new Message("INVALID MESSAGE"), new Object[0]); 216 } 217 } 218 219 /** 220 * SLog wrapper. 221 */ 222 @VisibleForTesting passToLogcat(String tag, LogLevel level, String message)223 public void passToLogcat(String tag, LogLevel level, String message) { 224 switch (level) { 225 case DEBUG: 226 Slog.d(tag, message); 227 break; 228 case VERBOSE: 229 Slog.v(tag, message); 230 break; 231 case INFO: 232 Slog.i(tag, message); 233 break; 234 case WARN: 235 Slog.w(tag, message); 236 break; 237 case ERROR: 238 Slog.e(tag, message); 239 break; 240 case WTF: 241 Slog.wtf(tag, message); 242 break; 243 } 244 } 245 246 /** 247 * Returns {@code true} iff logging to proto is enabled. 248 */ isProtoEnabled()249 public boolean isProtoEnabled() { 250 return mTracingInstances.get() > 0; 251 } 252 253 @Override toggleLogcat(boolean enabled, String[] groups)254 public void toggleLogcat(boolean enabled, String[] groups) { 255 final ILogger logger = (message) -> Log.d(LOG_TAG, message); 256 if (enabled) { 257 startLoggingToLogcat(groups, logger); 258 } else { 259 stopLoggingToLogcat(groups, logger); 260 } 261 } 262 263 /** 264 * Start text logging 265 * @param groups Groups to start text logging for 266 * @param logger A logger to write status updates to 267 * @return status code 268 */ startLoggingToLogcat(String[] groups, @NonNull ILogger logger)269 public int startLoggingToLogcat(String[] groups, @NonNull ILogger logger) { 270 return setTextLogging(true, logger, groups); 271 } 272 273 /** 274 * Stop text logging 275 * @param groups Groups to start text logging for 276 * @param logger A logger to write status updates to 277 * @return status code 278 */ stopLoggingToLogcat(String[] groups, @NonNull ILogger logger)279 public int stopLoggingToLogcat(String[] groups, @NonNull ILogger logger) { 280 return setTextLogging(false, logger, groups); 281 } 282 283 @Override isEnabled(IProtoLogGroup group, LogLevel level)284 public boolean isEnabled(IProtoLogGroup group, LogLevel level) { 285 final int[] groupLevelCount = mLogLevelCounts.get(group.name()); 286 return (groupLevelCount == null && mDefaultLogLevelCounts[level.ordinal()] > 0) 287 || (groupLevelCount != null && groupLevelCount[level.ordinal()] > 0) 288 || group.isLogToLogcat(); 289 } 290 291 @Override 292 @NonNull getRegisteredGroups()293 public List<IProtoLogGroup> getRegisteredGroups() { 294 return mLogGroups.values().stream().toList(); 295 } 296 registerGroupsLocally(@onNull IProtoLogGroup[] protoLogGroups)297 private void registerGroupsLocally(@NonNull IProtoLogGroup[] protoLogGroups) { 298 // Verify we don't have id collisions, if we do we want to know as soon as possible and 299 // we might want to manually specify an id for the group with a collision 300 verifyNoCollisionsOrDuplicates(protoLogGroups); 301 302 for (IProtoLogGroup protoLogGroup : protoLogGroups) { 303 mLogGroups.put(protoLogGroup.name(), protoLogGroup); 304 } 305 } 306 verifyNoCollisionsOrDuplicates(@onNull IProtoLogGroup[] protoLogGroups)307 private void verifyNoCollisionsOrDuplicates(@NonNull IProtoLogGroup[] protoLogGroups) { 308 final var groupId = new ArraySet<Integer>(); 309 310 for (IProtoLogGroup protoLogGroup : protoLogGroups) { 311 if (groupId.contains(protoLogGroup.getId())) { 312 throw new RuntimeException( 313 "Group with same id (" + protoLogGroup.getId() + ") registered twice. " 314 + "Potential duplicate or hash id collision."); 315 } 316 groupId.add(protoLogGroup.getId()); 317 } 318 } 319 readyToLogToLogcat()320 protected void readyToLogToLogcat() { 321 mLogcatReady = true; 322 } 323 324 /** 325 * Responds to a shell command. 326 */ 327 @Deprecated onShellCommand(ShellCommand shell)328 public int onShellCommand(ShellCommand shell) { 329 PrintWriter pw = shell.getOutPrintWriter(); 330 331 if (android.tracing.Flags.clientSideProtoLogging()) { 332 pw.println("Command deprecated. Please use 'cmd protolog_configuration' instead."); 333 return -1; 334 } 335 336 String cmd = shell.getNextArg(); 337 if (cmd == null) { 338 return unknownCommand(pw); 339 } 340 ArrayList<String> args = new ArrayList<>(); 341 String arg; 342 while ((arg = shell.getNextArg()) != null) { 343 args.add(arg); 344 } 345 final ILogger logger = (msg) -> logAndPrintln(pw, msg); 346 String[] groups = args.toArray(new String[0]); 347 switch (cmd) { 348 case "start", "stop" -> { 349 pw.println("Command not supported. " 350 + "Please start and stop ProtoLog tracing with Perfetto."); 351 return -1; 352 } 353 case "enable-text" -> { 354 return startLoggingToLogcat(groups, logger); 355 } 356 case "disable-text" -> { 357 return stopLoggingToLogcat(groups, logger); 358 } 359 default -> { 360 return unknownCommand(pw); 361 } 362 } 363 } 364 log(LogLevel logLevel, IProtoLogGroup group, Message message, @Nullable Object[] args)365 private void log(LogLevel logLevel, IProtoLogGroup group, Message message, 366 @Nullable Object[] args) { 367 if (isProtoEnabled()) { 368 long tsNanos = SystemClock.elapsedRealtimeNanos(); 369 final String stacktrace; 370 if (mCollectStackTraceGroupCounts.getOrDefault(group.name(), 0) > 0) { 371 stacktrace = collectStackTrace(); 372 } else { 373 stacktrace = null; 374 } 375 try { 376 mBackgroundServiceLock.lock(); 377 mBackgroundLoggingService.execute(() -> 378 logToProto(logLevel, group, message, args, tsNanos, 379 stacktrace)); 380 } finally { 381 mBackgroundServiceLock.unlock(); 382 } 383 } 384 if (group.isLogToLogcat()) { 385 logToLogcat(group.getTag(), logLevel, message, args); 386 } 387 } 388 onTracingFlush()389 private void onTracingFlush() { 390 Log.d(LOG_TAG, "Executing onTracingFlush"); 391 392 final ExecutorService loggingService; 393 try { 394 mBackgroundServiceLock.lock(); 395 loggingService = mBackgroundLoggingService; 396 mBackgroundLoggingService = Executors.newSingleThreadExecutor(); 397 } finally { 398 mBackgroundServiceLock.unlock(); 399 } 400 401 try { 402 loggingService.shutdown(); 403 boolean finished = loggingService.awaitTermination(10, TimeUnit.SECONDS); 404 405 if (!finished) { 406 Log.e(LOG_TAG, "ProtoLog background tracing service didn't finish gracefully."); 407 } 408 } catch (InterruptedException e) { 409 Log.e(LOG_TAG, "Failed to wait for tracing to finish", e); 410 } 411 412 if (!android.tracing.Flags.clientSideProtoLogging()) { 413 dumpViewerConfig(); 414 } 415 416 Log.d(LOG_TAG, "Finished onTracingFlush"); 417 } 418 419 @Deprecated dumpViewerConfig()420 abstract void dumpViewerConfig(); 421 422 @NonNull getLogcatMessageString(@onNull Message message)423 abstract String getLogcatMessageString(@NonNull Message message); 424 logToLogcat(@onNull String tag, @NonNull LogLevel level, @NonNull Message message, @Nullable Object[] args)425 private void logToLogcat(@NonNull String tag, @NonNull LogLevel level, @NonNull Message message, 426 @Nullable Object[] args) { 427 if (!mLogcatReady) { 428 Log.w(LOG_TAG, "Trying to log a protolog message with hash " 429 + message.getMessageHash() + " to logcat before the service is ready to accept " 430 + "such requests."); 431 return; 432 } 433 434 String messageString = getLogcatMessageString(message); 435 logToLogcat(tag, level, messageString, args); 436 } 437 logToLogcat(String tag, LogLevel level, String messageString, @Nullable Object[] args)438 private void logToLogcat(String tag, LogLevel level, String messageString, 439 @Nullable Object[] args) { 440 String message; 441 if (args != null) { 442 try { 443 message = TextUtils.formatSimple(messageString, args); 444 } catch (IllegalArgumentException e) { 445 message = "FORMAT_ERROR \"" + messageString + "\", args=(" 446 + String.join( 447 ", ", Arrays.stream(args).map(Object::toString).toList()) + ")"; 448 } 449 } else { 450 message = messageString; 451 } 452 passToLogcat(tag, level, message); 453 } 454 logToProto(LogLevel level, IProtoLogGroup logGroup, Message message, Object[] args, long tsNanos, @Nullable String stacktrace)455 private void logToProto(LogLevel level, IProtoLogGroup logGroup, Message message, Object[] args, 456 long tsNanos, @Nullable String stacktrace) { 457 mDataSource.trace(ctx -> { 458 final ProtoLogDataSource.TlsState tlsState = ctx.getCustomTlsState(); 459 final LogLevel logFrom = tlsState.getLogFromLevel(logGroup.name()); 460 461 if (level.ordinal() < logFrom.ordinal()) { 462 return; 463 } 464 465 if (args != null) { 466 // Intern all string params before creating the trace packet for the proto 467 // message so that the interned strings appear before in the trace to make the 468 // trace processing easier. 469 int argIndex = 0; 470 for (Object o : args) { 471 int type = LogDataType.bitmaskToLogDataType(message.getMessageMask(), argIndex); 472 if (type == LogDataType.STRING) { 473 if (o == null) { 474 internStringArg(ctx, NULL_STRING); 475 } else { 476 internStringArg(ctx, o.toString()); 477 } 478 } 479 argIndex++; 480 } 481 } 482 483 int internedStacktrace = 0; 484 if (tlsState.getShouldCollectStacktrace(logGroup.name())) { 485 // Intern stackstraces before creating the trace packet for the proto message so 486 // that the interned stacktrace strings appear before in the trace to make the 487 // trace processing easier. 488 internedStacktrace = internStacktraceString(ctx, stacktrace); 489 } 490 491 boolean needsIncrementalState = false; 492 493 long messageHash = 0; 494 if (message.mMessageHash != null) { 495 messageHash = message.mMessageHash; 496 } 497 if (message.mMessageString != null) { 498 needsIncrementalState = true; 499 messageHash = 500 internProtoMessage(ctx, level, logGroup, message.mMessageString); 501 } 502 503 final ProtoOutputStream os = ctx.newTracePacket(); 504 os.write(TIMESTAMP, tsNanos); 505 long token = os.start(PROTOLOG_MESSAGE); 506 507 os.write(MESSAGE_ID, messageHash); 508 509 if (args != null) { 510 511 int argIndex = 0; 512 LongArray longParams = new LongArray(); 513 ArrayList<Double> doubleParams = new ArrayList<>(); 514 ArrayList<Boolean> booleanParams = new ArrayList<>(); 515 for (Object o : args) { 516 int type = LogDataType.bitmaskToLogDataType(message.getMessageMask(), argIndex); 517 try { 518 switch (type) { 519 case LogDataType.STRING: 520 final int internedStringId; 521 if (o == null) { 522 internedStringId = internStringArg(ctx, NULL_STRING); 523 } else { 524 internedStringId = internStringArg(ctx, o.toString()); 525 } 526 os.write(STR_PARAM_IIDS, internedStringId); 527 needsIncrementalState = true; 528 break; 529 case LogDataType.LONG: 530 if (o == null) { 531 longParams.add(0); 532 } else { 533 longParams.add(((Number) o).longValue()); 534 } 535 break; 536 case LogDataType.DOUBLE: 537 if (o == null) { 538 doubleParams.add(0d); 539 } else { 540 doubleParams.add(((Number) o).doubleValue()); 541 } 542 break; 543 case LogDataType.BOOLEAN: 544 if (o == null) { 545 booleanParams.add(false); 546 } else { 547 booleanParams.add((boolean) o); 548 } 549 break; 550 } 551 } catch (ClassCastException ex) { 552 Slog.e(LOG_TAG, "Invalid ProtoLog paramsMask", ex); 553 } 554 argIndex++; 555 } 556 557 for (int i = 0; i < longParams.size(); ++i) { 558 os.write(SINT64_PARAMS, longParams.get(i)); 559 } 560 doubleParams.forEach(it -> os.write(DOUBLE_PARAMS, it)); 561 // Converting booleans to int because Perfetto doesn't yet support repeated 562 // booleans, so we use a repeated integers instead (b/313651412). 563 booleanParams.forEach(it -> os.write(BOOLEAN_PARAMS, it ? 1 : 0)); 564 } 565 566 if (tlsState.getShouldCollectStacktrace(logGroup.name())) { 567 os.write(STACKTRACE_IID, internedStacktrace); 568 } 569 570 os.end(token); 571 572 if (needsIncrementalState) { 573 os.write(SEQUENCE_FLAGS, SEQ_NEEDS_INCREMENTAL_STATE); 574 } 575 576 }); 577 } 578 internProtoMessage( TracingContext<ProtoLogDataSource.Instance, ProtoLogDataSource.TlsState, ProtoLogDataSource.IncrementalState> ctx, LogLevel level, IProtoLogGroup logGroup, String message)579 private long internProtoMessage( 580 TracingContext<ProtoLogDataSource.Instance, ProtoLogDataSource.TlsState, 581 ProtoLogDataSource.IncrementalState> ctx, LogLevel level, 582 IProtoLogGroup logGroup, String message) { 583 final ProtoLogDataSource.IncrementalState incrementalState = ctx.getIncrementalState(); 584 585 if (!incrementalState.clearReported) { 586 final ProtoOutputStream os = ctx.newTracePacket(); 587 os.write(SEQUENCE_FLAGS, SEQ_INCREMENTAL_STATE_CLEARED); 588 incrementalState.clearReported = true; 589 } 590 591 592 if (!incrementalState.protologGroupInterningSet.contains(logGroup.getId())) { 593 incrementalState.protologGroupInterningSet.add(logGroup.getId()); 594 595 final ProtoOutputStream os = ctx.newTracePacket(); 596 final long protologViewerConfigToken = os.start(PROTOLOG_VIEWER_CONFIG); 597 final long groupConfigToken = os.start(GROUPS); 598 599 os.write(ID, logGroup.getId()); 600 os.write(NAME, logGroup.name()); 601 os.write(TAG, logGroup.getTag()); 602 603 os.end(groupConfigToken); 604 os.end(protologViewerConfigToken); 605 } 606 607 final Long messageHash = hash(level, logGroup.name(), message); 608 if (!incrementalState.protologMessageInterningSet.contains(messageHash)) { 609 incrementalState.protologMessageInterningSet.add(messageHash); 610 611 final ProtoOutputStream os = ctx.newTracePacket(); 612 613 // Dependent on the ProtoLog viewer config packet that contains the group information. 614 os.write(SEQUENCE_FLAGS, SEQ_NEEDS_INCREMENTAL_STATE); 615 616 final long protologViewerConfigToken = os.start(PROTOLOG_VIEWER_CONFIG); 617 final long messageConfigToken = os.start(MESSAGES); 618 619 os.write(MessageData.MESSAGE_ID, messageHash); 620 os.write(MESSAGE, message); 621 os.write(LEVEL, level.id); 622 os.write(GROUP_ID, logGroup.getId()); 623 624 os.end(messageConfigToken); 625 os.end(protologViewerConfigToken); 626 } 627 628 return messageHash; 629 } 630 hash( LogLevel logLevel, String logGroup, String messageString )631 private Long hash( 632 LogLevel logLevel, 633 String logGroup, 634 String messageString 635 ) { 636 final String fullStringIdentifier = messageString + logLevel + logGroup; 637 return UUID.nameUUIDFromBytes(fullStringIdentifier.getBytes()).getMostSignificantBits(); 638 } 639 640 private static final int STACK_SIZE_TO_PROTO_LOG_ENTRY_CALL = 6; 641 collectStackTrace()642 private String collectStackTrace() { 643 StackTraceElement[] stackTrace = Thread.currentThread().getStackTrace(); 644 StringWriter sw = new StringWriter(); 645 try (PrintWriter pw = new PrintWriter(sw)) { 646 for (int i = STACK_SIZE_TO_PROTO_LOG_ENTRY_CALL; i < stackTrace.length; ++i) { 647 pw.println("\tat " + stackTrace[i]); 648 } 649 } 650 651 return sw.toString(); 652 } 653 internStacktraceString(TracingContext< ProtoLogDataSource.Instance, ProtoLogDataSource.TlsState, ProtoLogDataSource.IncrementalState> ctx, String stacktrace)654 private int internStacktraceString(TracingContext< 655 ProtoLogDataSource.Instance, 656 ProtoLogDataSource.TlsState, 657 ProtoLogDataSource.IncrementalState> ctx, 658 String stacktrace) { 659 final ProtoLogDataSource.IncrementalState incrementalState = ctx.getIncrementalState(); 660 return internString(ctx, incrementalState.stacktraceInterningMap, 661 PROTOLOG_STACKTRACE, stacktrace); 662 } 663 internStringArg( TracingContext<ProtoLogDataSource.Instance, ProtoLogDataSource.TlsState, ProtoLogDataSource.IncrementalState> ctx, String string )664 private int internStringArg( 665 TracingContext<ProtoLogDataSource.Instance, ProtoLogDataSource.TlsState, 666 ProtoLogDataSource.IncrementalState> ctx, 667 String string 668 ) { 669 final ProtoLogDataSource.IncrementalState incrementalState = ctx.getIncrementalState(); 670 return internString(ctx, incrementalState.argumentInterningMap, 671 PROTOLOG_STRING_ARGS, string); 672 } 673 internString( TracingContext<ProtoLogDataSource.Instance, ProtoLogDataSource.TlsState, ProtoLogDataSource.IncrementalState> ctx, Map<String, Integer> internMap, long fieldId, @NonNull String string )674 private int internString( 675 TracingContext<ProtoLogDataSource.Instance, ProtoLogDataSource.TlsState, 676 ProtoLogDataSource.IncrementalState> ctx, 677 Map<String, Integer> internMap, 678 long fieldId, 679 @NonNull String string 680 ) { 681 final ProtoLogDataSource.IncrementalState incrementalState = ctx.getIncrementalState(); 682 683 if (!incrementalState.clearReported) { 684 final ProtoOutputStream os = ctx.newTracePacket(); 685 os.write(SEQUENCE_FLAGS, SEQ_INCREMENTAL_STATE_CLEARED); 686 incrementalState.clearReported = true; 687 } 688 689 if (!internMap.containsKey(string)) { 690 final int internedIndex = internMap.size() + 1; 691 internMap.put(string, internedIndex); 692 693 final ProtoOutputStream os = ctx.newTracePacket(); 694 final long token = os.start(INTERNED_DATA); 695 final long innerToken = os.start(fieldId); 696 os.write(IID, internedIndex); 697 os.write(STR, string.getBytes()); 698 os.end(innerToken); 699 os.end(token); 700 } 701 702 return internMap.get(string); 703 } 704 validateGroups(ILogger logger, String[] groups)705 protected boolean validateGroups(ILogger logger, String[] groups) { 706 for (int i = 0; i < groups.length; i++) { 707 String group = groups[i]; 708 IProtoLogGroup g = mLogGroups.get(group); 709 if (g == null) { 710 logger.log("No IProtoLogGroup named " + group); 711 return false; 712 } 713 } 714 return true; 715 } 716 setTextLogging(boolean value, ILogger logger, String... groups)717 private int setTextLogging(boolean value, ILogger logger, String... groups) { 718 if (!validateGroups(logger, groups)) { 719 return -1; 720 } 721 722 for (int i = 0; i < groups.length; i++) { 723 String group = groups[i]; 724 IProtoLogGroup g = mLogGroups.get(group); 725 if (g != null) { 726 g.setLogToLogcat(value); 727 } else { 728 throw new RuntimeException("No IProtoLogGroup named " + group); 729 } 730 } 731 732 mCacheUpdater.update(this); 733 return 0; 734 } 735 unknownCommand(PrintWriter pw)736 private int unknownCommand(PrintWriter pw) { 737 pw.println("Unknown command"); 738 pw.println("Window manager logging options:"); 739 pw.println(" enable-text [group...]: Enable logcat logging for given groups"); 740 pw.println(" disable-text [group...]: Disable logcat logging for given groups"); 741 return -1; 742 } 743 onTracingInstanceStart( int instanceIdx, ProtoLogDataSource.ProtoLogConfig config)744 private synchronized void onTracingInstanceStart( 745 int instanceIdx, ProtoLogDataSource.ProtoLogConfig config) { 746 Log.d(LOG_TAG, "Executing onTracingInstanceStart"); 747 748 final LogLevel defaultLogFrom = config.getDefaultGroupConfig().logFrom; 749 for (int i = defaultLogFrom.ordinal(); i < LogLevel.values().length; i++) { 750 mDefaultLogLevelCounts[i]++; 751 } 752 753 final Set<String> overriddenGroupTags = config.getGroupTagsWithOverriddenConfigs(); 754 755 for (String overriddenGroupTag : overriddenGroupTags) { 756 mLogLevelCounts.putIfAbsent(overriddenGroupTag, new int[LogLevel.values().length]); 757 final int[] logLevelsCountsForGroup = mLogLevelCounts.get(overriddenGroupTag); 758 759 final LogLevel logFromLevel = config.getConfigFor(overriddenGroupTag).logFrom; 760 for (int i = logFromLevel.ordinal(); i < LogLevel.values().length; i++) { 761 logLevelsCountsForGroup[i]++; 762 } 763 764 if (config.getConfigFor(overriddenGroupTag).collectStackTrace) { 765 mCollectStackTraceGroupCounts.put(overriddenGroupTag, 766 mCollectStackTraceGroupCounts.getOrDefault(overriddenGroupTag, 0) + 1); 767 } 768 769 if (config.getConfigFor(overriddenGroupTag).collectStackTrace) { 770 mCollectStackTraceGroupCounts.put(overriddenGroupTag, 771 mCollectStackTraceGroupCounts.getOrDefault(overriddenGroupTag, 0) + 1); 772 } 773 } 774 775 mCacheUpdater.update(this); 776 777 this.mTracingInstances.incrementAndGet(); 778 779 Log.d(LOG_TAG, "Finished onTracingInstanceStart"); 780 } 781 onTracingInstanceStop( int instanceIdx, ProtoLogDataSource.ProtoLogConfig config)782 private synchronized void onTracingInstanceStop( 783 int instanceIdx, ProtoLogDataSource.ProtoLogConfig config) { 784 Log.d(LOG_TAG, "Executing onTracingInstanceStop"); 785 this.mTracingInstances.decrementAndGet(); 786 787 final LogLevel defaultLogFrom = config.getDefaultGroupConfig().logFrom; 788 for (int i = defaultLogFrom.ordinal(); i < LogLevel.values().length; i++) { 789 mDefaultLogLevelCounts[i]--; 790 } 791 792 final Set<String> overriddenGroupTags = config.getGroupTagsWithOverriddenConfigs(); 793 794 for (String overriddenGroupTag : overriddenGroupTags) { 795 final int[] logLevelsCountsForGroup = mLogLevelCounts.get(overriddenGroupTag); 796 797 final LogLevel logFromLevel = config.getConfigFor(overriddenGroupTag).logFrom; 798 for (int i = logFromLevel.ordinal(); i < LogLevel.values().length; i++) { 799 logLevelsCountsForGroup[i]--; 800 } 801 if (Arrays.stream(logLevelsCountsForGroup).allMatch(it -> it == 0)) { 802 mLogLevelCounts.remove(overriddenGroupTag); 803 } 804 805 if (config.getConfigFor(overriddenGroupTag).collectStackTrace) { 806 mCollectStackTraceGroupCounts.put(overriddenGroupTag, 807 mCollectStackTraceGroupCounts.get(overriddenGroupTag) - 1); 808 809 if (mCollectStackTraceGroupCounts.get(overriddenGroupTag) == 0) { 810 mCollectStackTraceGroupCounts.remove(overriddenGroupTag); 811 } 812 } 813 } 814 815 mCacheUpdater.update(this); 816 Log.d(LOG_TAG, "Finished onTracingInstanceStop"); 817 } 818 logAndPrintln(@ullable PrintWriter pw, String msg)819 private static void logAndPrintln(@Nullable PrintWriter pw, String msg) { 820 Slog.i(LOG_TAG, msg); 821 if (pw != null) { 822 pw.println(msg); 823 pw.flush(); 824 } 825 } 826 827 protected static class Message { 828 @Nullable 829 private final Long mMessageHash; 830 private final int mMessageMask; 831 @Nullable 832 private final String mMessageString; 833 Message(long messageHash, int messageMask)834 private Message(long messageHash, int messageMask) { 835 this.mMessageHash = messageHash; 836 this.mMessageMask = messageMask; 837 this.mMessageString = null; 838 } 839 Message(@onNull String messageString)840 private Message(@NonNull String messageString) throws InvalidFormatStringException { 841 this.mMessageHash = null; 842 final List<Integer> argTypes = LogDataType.parseFormatString(messageString); 843 this.mMessageMask = LogDataType.logDataTypesToBitMask(argTypes); 844 this.mMessageString = messageString; 845 } 846 getMessageMask()847 private int getMessageMask() { 848 return mMessageMask; 849 } 850 851 @Nullable getMessageHash()852 protected Long getMessageHash() { 853 return mMessageHash; 854 } 855 856 @Nullable getMessage()857 protected String getMessage() { 858 return mMessageString; 859 } 860 861 @Nullable getMessage(@onNull ProtoLogViewerConfigReader viewerConfigReader)862 protected String getMessage(@NonNull ProtoLogViewerConfigReader viewerConfigReader) { 863 if (mMessageString != null) { 864 return mMessageString; 865 } 866 867 if (mMessageHash != null) { 868 return viewerConfigReader.getViewerString(mMessageHash); 869 } 870 871 throw new RuntimeException("Both mMessageString and mMessageHash should never be null"); 872 } 873 } 874 875 /** 876 * This is only used by unit tests to wait until {@link #connectToConfigurationService} is 877 * done. Because unit tests are sensitive to concurrent accesses. 878 */ 879 @VisibleForTesting waitForInitialization()880 public static void waitForInitialization() { 881 final IProtoLog currentInstance = ProtoLog.getSingleInstance(); 882 if (!(currentInstance instanceof PerfettoProtoLogImpl protoLog)) { 883 return; 884 } 885 try { 886 protoLog.mBackgroundLoggingService.submit(() -> { 887 Log.i(LOG_TAG, "Complete initialization"); 888 }).get(); 889 } catch (InterruptedException | ExecutionException e) { 890 Log.e(LOG_TAG, "Failed to wait for tracing service", e); 891 } 892 } 893 } 894 895