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 com.android.internal.protolog.ProtoLogFileProto.LOG; 20 import static com.android.internal.protolog.ProtoLogFileProto.MAGIC_NUMBER; 21 import static com.android.internal.protolog.ProtoLogFileProto.MAGIC_NUMBER_H; 22 import static com.android.internal.protolog.ProtoLogFileProto.MAGIC_NUMBER_L; 23 import static com.android.internal.protolog.ProtoLogFileProto.REAL_TIME_TO_ELAPSED_TIME_OFFSET_MILLIS; 24 import static com.android.internal.protolog.ProtoLogFileProto.VERSION; 25 import static com.android.internal.protolog.ProtoLogMessage.BOOLEAN_PARAMS; 26 import static com.android.internal.protolog.ProtoLogMessage.DOUBLE_PARAMS; 27 import static com.android.internal.protolog.ProtoLogMessage.ELAPSED_REALTIME_NANOS; 28 import static com.android.internal.protolog.ProtoLogMessage.MESSAGE_HASH; 29 import static com.android.internal.protolog.ProtoLogMessage.SINT64_PARAMS; 30 import static com.android.internal.protolog.ProtoLogMessage.STR_PARAMS; 31 32 import android.annotation.NonNull; 33 import android.annotation.Nullable; 34 import android.os.ShellCommand; 35 import android.os.SystemClock; 36 import android.text.TextUtils; 37 import android.util.Slog; 38 import android.util.proto.ProtoOutputStream; 39 40 import com.android.internal.annotations.VisibleForTesting; 41 import com.android.internal.protolog.common.ILogger; 42 import com.android.internal.protolog.common.IProtoLog; 43 import com.android.internal.protolog.common.IProtoLogGroup; 44 import com.android.internal.protolog.common.LogDataType; 45 import com.android.internal.protolog.common.LogLevel; 46 import com.android.internal.util.TraceBuffer; 47 48 import java.io.File; 49 import java.io.IOException; 50 import java.io.PrintWriter; 51 import java.util.ArrayList; 52 import java.util.Arrays; 53 import java.util.List; 54 import java.util.Map; 55 import java.util.TreeMap; 56 import java.util.stream.Collectors; 57 58 /** 59 * A service for the ProtoLog logging system. 60 */ 61 public class LegacyProtoLogImpl implements IProtoLog { 62 private static final int BUFFER_CAPACITY = 1024 * 1024; 63 private static final int PER_CHUNK_SIZE = 1024; 64 private static final String TAG = "ProtoLog"; 65 private static final long MAGIC_NUMBER_VALUE = ((long) MAGIC_NUMBER_H << 32) | MAGIC_NUMBER_L; 66 static final String PROTOLOG_VERSION = "2.0.0"; 67 68 private final File mLogFile; 69 private final String mLegacyViewerConfigFilename; 70 private final TraceBuffer mBuffer; 71 private final LegacyProtoLogViewerConfigReader mViewerConfig; 72 private final Map<String, IProtoLogGroup> mLogGroups = new TreeMap<>(); 73 private final ProtoLogCacheUpdater mCacheUpdater; 74 private final int mPerChunkSize; 75 76 private boolean mProtoLogEnabled; 77 private boolean mProtoLogEnabledLockFree; 78 private final Object mProtoLogEnabledLock = new Object(); 79 LegacyProtoLogImpl(String outputFile, String viewerConfigFilename, ProtoLogCacheUpdater cacheUpdater)80 public LegacyProtoLogImpl(String outputFile, String viewerConfigFilename, 81 ProtoLogCacheUpdater cacheUpdater) { 82 this(new File(outputFile), viewerConfigFilename, BUFFER_CAPACITY, 83 new LegacyProtoLogViewerConfigReader(), PER_CHUNK_SIZE, cacheUpdater); 84 } 85 LegacyProtoLogImpl(File file, String viewerConfigFilename, int bufferCapacity, LegacyProtoLogViewerConfigReader viewerConfig, int perChunkSize, ProtoLogCacheUpdater cacheUpdater)86 public LegacyProtoLogImpl(File file, String viewerConfigFilename, int bufferCapacity, 87 LegacyProtoLogViewerConfigReader viewerConfig, int perChunkSize, 88 ProtoLogCacheUpdater cacheUpdater) { 89 mLogFile = file; 90 mBuffer = new TraceBuffer(bufferCapacity); 91 mLegacyViewerConfigFilename = viewerConfigFilename; 92 mViewerConfig = viewerConfig; 93 mPerChunkSize = perChunkSize; 94 mCacheUpdater = cacheUpdater; 95 } 96 97 /** 98 * Main log method, do not call directly. 99 */ 100 @VisibleForTesting 101 @Override log(LogLevel level, IProtoLogGroup group, long messageHash, int paramsMask, @Nullable Object[] args)102 public void log(LogLevel level, IProtoLogGroup group, long messageHash, int paramsMask, 103 @Nullable Object[] args) { 104 if (group.isLogToProto()) { 105 logToProto(messageHash, paramsMask, args); 106 } 107 if (group.isLogToLogcat()) { 108 logToLogcat(group.getTag(), level, messageHash, args); 109 } 110 } 111 112 @Override log(LogLevel logLevel, IProtoLogGroup group, String messageString, Object... args)113 public void log(LogLevel logLevel, IProtoLogGroup group, String messageString, Object... args) { 114 // This will be removed very soon so no point implementing it here. 115 throw new IllegalStateException( 116 "Not implemented. Only implemented for PerfettoProtoLogImpl."); 117 } 118 logToLogcat(String tag, LogLevel level, long messageHash, @Nullable Object[] args)119 private void logToLogcat(String tag, LogLevel level, long messageHash, 120 @Nullable Object[] args) { 121 String message = null; 122 final String messageString = mViewerConfig.getViewerString(messageHash); 123 if (messageString != null) { 124 if (args != null) { 125 try { 126 message = TextUtils.formatSimple(messageString, args); 127 } catch (Exception ex) { 128 Slog.w(TAG, "Invalid ProtoLog format string.", ex); 129 } 130 } else { 131 message = messageString; 132 } 133 } 134 if (message == null) { 135 StringBuilder builder = new StringBuilder("UNKNOWN MESSAGE (" + messageHash + ")"); 136 if (args != null) { 137 for (Object o : args) { 138 builder.append(" ").append(o); 139 } 140 } 141 message = builder.toString(); 142 } 143 passToLogcat(tag, level, message); 144 } 145 146 /** 147 * SLog wrapper. 148 */ 149 @VisibleForTesting passToLogcat(String tag, LogLevel level, String message)150 public void passToLogcat(String tag, LogLevel level, String message) { 151 switch (level) { 152 case DEBUG: 153 Slog.d(tag, message); 154 break; 155 case VERBOSE: 156 Slog.v(tag, message); 157 break; 158 case INFO: 159 Slog.i(tag, message); 160 break; 161 case WARN: 162 Slog.w(tag, message); 163 break; 164 case ERROR: 165 Slog.e(tag, message); 166 break; 167 case WTF: 168 Slog.wtf(tag, message); 169 break; 170 } 171 } 172 logToProto(long messageHash, int paramsMask, Object[] args)173 private void logToProto(long messageHash, int paramsMask, Object[] args) { 174 if (!isProtoEnabled()) { 175 return; 176 } 177 try { 178 ProtoOutputStream os = new ProtoOutputStream(mPerChunkSize); 179 long token = os.start(LOG); 180 os.write(MESSAGE_HASH, messageHash); 181 os.write(ELAPSED_REALTIME_NANOS, SystemClock.elapsedRealtimeNanos()); 182 183 if (args != null) { 184 int argIndex = 0; 185 ArrayList<Long> longParams = new ArrayList<>(); 186 ArrayList<Double> doubleParams = new ArrayList<>(); 187 ArrayList<Boolean> booleanParams = new ArrayList<>(); 188 for (Object o : args) { 189 int type = LogDataType.bitmaskToLogDataType(paramsMask, argIndex); 190 try { 191 switch (type) { 192 case LogDataType.STRING: 193 os.write(STR_PARAMS, o.toString()); 194 break; 195 case LogDataType.LONG: 196 longParams.add(((Number) o).longValue()); 197 break; 198 case LogDataType.DOUBLE: 199 doubleParams.add(((Number) o).doubleValue()); 200 break; 201 case LogDataType.BOOLEAN: 202 booleanParams.add((boolean) o); 203 break; 204 } 205 } catch (ClassCastException ex) { 206 // Should not happen unless there is an error in the ProtoLogTool. 207 os.write(STR_PARAMS, "(INVALID PARAMS_MASK) " + o.toString()); 208 Slog.e(TAG, "Invalid ProtoLog paramsMask", ex); 209 } 210 argIndex++; 211 } 212 if (longParams.size() > 0) { 213 os.writePackedSInt64(SINT64_PARAMS, 214 longParams.stream().mapToLong(i -> i).toArray()); 215 } 216 if (doubleParams.size() > 0) { 217 os.writePackedDouble(DOUBLE_PARAMS, 218 doubleParams.stream().mapToDouble(i -> i).toArray()); 219 } 220 if (booleanParams.size() > 0) { 221 boolean[] arr = new boolean[booleanParams.size()]; 222 for (int i = 0; i < booleanParams.size(); i++) { 223 arr[i] = booleanParams.get(i); 224 } 225 os.writePackedBool(BOOLEAN_PARAMS, arr); 226 } 227 } 228 os.end(token); 229 mBuffer.add(os); 230 } catch (Exception e) { 231 Slog.e(TAG, "Exception while logging to proto", e); 232 } 233 } 234 235 /** 236 * Starts the logging a circular proto buffer. 237 * 238 * @param pw Print writer 239 */ startProtoLog(@ullable PrintWriter pw)240 public void startProtoLog(@Nullable PrintWriter pw) { 241 if (isProtoEnabled()) { 242 return; 243 } 244 synchronized (mProtoLogEnabledLock) { 245 logAndPrintln(pw, "Start logging to " + mLogFile + "."); 246 mBuffer.resetBuffer(); 247 mProtoLogEnabled = true; 248 mProtoLogEnabledLockFree = true; 249 } 250 } 251 252 /** 253 * Stops logging to proto. 254 * 255 * @param pw Print writer 256 * @param writeToFile If the current buffer should be written to disk or not 257 */ stopProtoLog(@ullable PrintWriter pw, boolean writeToFile)258 public void stopProtoLog(@Nullable PrintWriter pw, boolean writeToFile) { 259 if (!isProtoEnabled()) { 260 return; 261 } 262 synchronized (mProtoLogEnabledLock) { 263 logAndPrintln(pw, "Stop logging to " + mLogFile + ". Waiting for log to flush."); 264 mProtoLogEnabled = mProtoLogEnabledLockFree = false; 265 if (writeToFile) { 266 writeProtoLogToFileLocked(); 267 logAndPrintln(pw, "Log written to " + mLogFile + "."); 268 mBuffer.resetBuffer(); 269 } 270 if (mProtoLogEnabled) { 271 logAndPrintln(pw, "ERROR: logging was re-enabled while waiting for flush."); 272 throw new IllegalStateException("logging enabled while waiting for flush."); 273 } 274 } 275 } 276 277 /** 278 * Returns {@code true} iff logging to proto is enabled. 279 */ isProtoEnabled()280 public boolean isProtoEnabled() { 281 return mProtoLogEnabledLockFree; 282 } 283 setLogging(boolean setTextLogging, boolean value, ILogger logger, String... groups)284 private int setLogging(boolean setTextLogging, boolean value, ILogger logger, 285 String... groups) { 286 for (int i = 0; i < groups.length; i++) { 287 String group = groups[i]; 288 IProtoLogGroup g = mLogGroups.get(group); 289 if (g != null) { 290 if (setTextLogging) { 291 g.setLogToLogcat(value); 292 } else { 293 g.setLogToProto(value); 294 } 295 } else { 296 logger.log("No IProtoLogGroup named " + group); 297 return -1; 298 } 299 } 300 301 mCacheUpdater.update(this); 302 return 0; 303 } 304 unknownCommand(PrintWriter pw)305 private int unknownCommand(PrintWriter pw) { 306 pw.println("Unknown command"); 307 pw.println("Window manager logging options:"); 308 pw.println(" start: Start proto logging"); 309 pw.println(" stop: Stop proto logging"); 310 pw.println(" enable [group...]: Enable proto logging for given groups"); 311 pw.println(" disable [group...]: Disable proto logging for given groups"); 312 pw.println(" enable-text [group...]: Enable logcat logging for given groups"); 313 pw.println(" disable-text [group...]: Disable logcat logging for given groups"); 314 return -1; 315 } 316 317 /** 318 * Responds to a shell command. 319 */ onShellCommand(ShellCommand shell)320 public int onShellCommand(ShellCommand shell) { 321 PrintWriter pw = shell.getOutPrintWriter(); 322 String cmd = shell.getNextArg(); 323 if (cmd == null) { 324 return unknownCommand(pw); 325 } 326 ArrayList<String> args = new ArrayList<>(); 327 String arg; 328 while ((arg = shell.getNextArg()) != null) { 329 args.add(arg); 330 } 331 final ILogger logger = (msg) -> logAndPrintln(pw, msg); 332 String[] groups = args.toArray(new String[args.size()]); 333 switch (cmd) { 334 case "start": 335 startProtoLog(pw); 336 return 0; 337 case "stop": 338 stopProtoLog(pw, true); 339 return 0; 340 case "status": 341 logAndPrintln(pw, getStatus()); 342 return 0; 343 case "enable": 344 return setLogging(false, true, logger, groups); 345 case "enable-text": 346 mViewerConfig.loadViewerConfig(logger, mLegacyViewerConfigFilename); 347 return setLogging(true, true, logger, groups); 348 case "disable": 349 return setLogging(false, false, logger, groups); 350 case "disable-text": 351 return setLogging(true, false, logger, groups); 352 default: 353 return unknownCommand(pw); 354 } 355 } 356 357 /** 358 * Returns a human-readable ProtoLog status text. 359 */ getStatus()360 public String getStatus() { 361 return "ProtoLog status: " 362 + ((isProtoEnabled()) ? "Enabled" : "Disabled") 363 + "\nEnabled log groups: \n Proto: " 364 + mLogGroups.values().stream().filter( 365 it -> it.isEnabled() && it.isLogToProto()) 366 .map(IProtoLogGroup::name).collect(Collectors.joining(" ")) 367 + "\n Logcat: " 368 + mLogGroups.values().stream().filter( 369 it -> it.isEnabled() && it.isLogToLogcat()) 370 .map(IProtoLogGroup::name).collect(Collectors.joining(" ")) 371 + "\nLogging definitions loaded: " + mViewerConfig.knownViewerStringsNumber(); 372 } 373 writeProtoLogToFileLocked()374 private void writeProtoLogToFileLocked() { 375 try { 376 long offset = 377 (System.currentTimeMillis() - (SystemClock.elapsedRealtimeNanos() / 1000000)); 378 ProtoOutputStream proto = new ProtoOutputStream(mPerChunkSize); 379 proto.write(MAGIC_NUMBER, MAGIC_NUMBER_VALUE); 380 proto.write(VERSION, PROTOLOG_VERSION); 381 proto.write(REAL_TIME_TO_ELAPSED_TIME_OFFSET_MILLIS, offset); 382 mBuffer.writeTraceToFile(mLogFile, proto); 383 } catch (IOException e) { 384 Slog.e(TAG, "Unable to write buffer to file", e); 385 } 386 } 387 logAndPrintln(@ullable PrintWriter pw, String msg)388 static void logAndPrintln(@Nullable PrintWriter pw, String msg) { 389 Slog.i(TAG, msg); 390 if (pw != null) { 391 pw.println(msg); 392 pw.flush(); 393 } 394 } 395 396 /** 397 * Start text logging 398 * @param groups Groups to start text logging for 399 * @param logger A logger to write status updates to 400 * @return status code 401 */ startLoggingToLogcat(String[] groups, ILogger logger)402 public int startLoggingToLogcat(String[] groups, ILogger logger) { 403 mViewerConfig.loadViewerConfig(logger, mLegacyViewerConfigFilename); 404 return setLogging(true /* setTextLogging */, true, logger, groups); 405 } 406 407 /** 408 * Stop text logging 409 * @param groups Groups to start text logging for 410 * @param logger A logger to write status updates to 411 * @return status code 412 */ stopLoggingToLogcat(String[] groups, ILogger logger)413 public int stopLoggingToLogcat(String[] groups, ILogger logger) { 414 return setLogging(true /* setTextLogging */, false, logger, groups); 415 } 416 417 @Override isEnabled(IProtoLogGroup group, LogLevel level)418 public boolean isEnabled(IProtoLogGroup group, LogLevel level) { 419 // In legacy logging we just enable an entire group at a time without more granular control, 420 // so we ignore the level argument to this function. 421 return group.isLogToLogcat() || (group.isLogToProto() && isProtoEnabled()); 422 } 423 424 @Override 425 @NonNull getRegisteredGroups()426 public List<IProtoLogGroup> getRegisteredGroups() { 427 return mLogGroups.values().stream().toList(); 428 } 429 registerGroups(IProtoLogGroup... protoLogGroups)430 public void registerGroups(IProtoLogGroup... protoLogGroups) { 431 for (IProtoLogGroup group : protoLogGroups) { 432 mLogGroups.put(group.name(), group); 433 } 434 435 final var hasGroupsLoggingToLogcat = Arrays.stream(protoLogGroups) 436 .anyMatch(IProtoLogGroup::isLogToLogcat); 437 438 final ILogger logger = (msg) -> Slog.i(TAG, msg); 439 if (hasGroupsLoggingToLogcat) { 440 mViewerConfig.loadViewerConfig(logger, mLegacyViewerConfigFilename); 441 } 442 } 443 } 444 445