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