• Home
  • Line#
  • Scopes#
  • Navigate#
  • Raw
  • Download
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