• 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 android.os.profiling;
18 
19 import android.annotation.NonNull;
20 import android.annotation.Nullable;
21 import android.content.Context;
22 import android.icu.text.SimpleDateFormat;
23 import android.icu.util.Calendar;
24 import android.icu.util.TimeZone;
25 import android.os.Binder;
26 import android.os.Bundle;
27 import android.os.Environment;
28 import android.os.FileUtils;
29 import android.os.Handler;
30 import android.os.HandlerThread;
31 import android.os.IBinder;
32 import android.os.IProfilingResultCallback;
33 import android.os.IProfilingService;
34 import android.os.ParcelFileDescriptor;
35 import android.os.ProfilingManager;
36 import android.os.ProfilingResult;
37 import android.os.ProfilingTrigger;
38 import android.os.ProfilingTriggerValueParcel;
39 import android.os.ProfilingTriggersWrapper;
40 import android.os.QueuedResultsWrapper;
41 import android.os.RemoteException;
42 import android.provider.DeviceConfig;
43 import android.text.TextUtils;
44 import android.util.ArrayMap;
45 import android.util.AtomicFile;
46 import android.util.Log;
47 import android.util.SparseArray;
48 
49 import com.android.internal.annotations.GuardedBy;
50 import com.android.internal.annotations.VisibleForTesting;
51 import com.android.server.SystemService;
52 
53 import java.io.File;
54 import java.io.FileInputStream;
55 import java.io.FileOutputStream;
56 import java.io.FilenameFilter;
57 import java.io.IOException;
58 import java.nio.file.Files;
59 import java.nio.file.Path;
60 import java.util.ArrayList;
61 import java.util.Arrays;
62 import java.util.List;
63 import java.util.Locale;
64 import java.util.Random;
65 import java.util.Set;
66 import java.util.UUID;
67 import java.util.concurrent.Executors;
68 import java.util.concurrent.ScheduledExecutorService;
69 import java.util.concurrent.ScheduledFuture;
70 import java.util.concurrent.TimeUnit;
71 import java.util.concurrent.atomic.AtomicInteger;
72 import java.util.function.Consumer;
73 
74 public class ProfilingService extends IProfilingService.Stub {
75     private static final String TAG = ProfilingService.class.getSimpleName();
76     private static final boolean DEBUG = false;
77 
78     private static final String TEMP_TRACE_PATH = "/data/misc/perfetto-traces/profiling/";
79     private static final String OUTPUT_FILE_RELATIVE_PATH = "/profiling/";
80     private static final String OUTPUT_FILE_SECTION_SEPARATOR = "_";
81     private static final String OUTPUT_FILE_PREFIX = "profile";
82     // Keep in sync with {@link ProfilingFrameworkTests}.
83     private static final String OUTPUT_FILE_JAVA_HEAP_DUMP_SUFFIX = ".perfetto-java-heap-dump";
84     private static final String OUTPUT_FILE_HEAP_PROFILE_SUFFIX = ".perfetto-heap-profile";
85     private static final String OUTPUT_FILE_STACK_SAMPLING_SUFFIX = ".perfetto-stack-sample";
86     private static final String OUTPUT_FILE_TRACE_SUFFIX = ".perfetto-trace";
87     private static final String OUTPUT_FILE_UNREDACTED_TRACE_SUFFIX = ".perfetto-trace-unredacted";
88     private static final String OUTPUT_FILE_TRIGGER = "trigger";
89     private static final String OUTPUT_FILE_IN_PROGRESS = "in-progress";
90 
91     private static final String PERSIST_SYSTEM_DIR = "system";
92     private static final String PERSIST_STORE_DIR = "profiling_service_data";
93     private static final String QUEUED_RESULTS_INFO_FILE = "profiling_queued_results_info";
94     private static final String APP_TRIGGERS_INFO_FILE = "profiling_app_triggers_info";
95 
96     // Used for unique session name only, not filename.
97     private static final String SYSTEM_TRIGGERED_SESSION_NAME_PREFIX = "system_triggered_session_";
98 
99     private static final int TAG_MAX_CHARS_FOR_FILENAME = 20;
100 
101     private static final int PERFETTO_DESTROY_DEFAULT_TIMEOUT_MS = 10 * 1000;
102 
103     private static final int DEFAULT_MAX_RESULT_REDELIVERY_COUNT = 3;
104 
105     private static final int REDACTION_DEFAULT_MAX_RUNTIME_ALLOTTED_MS = 20  * 1000;
106 
107     private static final int REDACTION_DEFAULT_CHECK_FREQUENCY_MS = 2 * 1000;
108 
109     // The cadence at which the profiling process will be checked after the initial delay
110     // has elapsed.
111     private static final int PROFILING_DEFAULT_RECHECK_DELAY_MS = 5 * 1000;
112 
113     private static final int CLEAR_TEMPORARY_DIRECTORY_FREQUENCY_DEFAULT_MS = 24 * 60 * 60 * 1000;
114     private static final int CLEAR_TEMPORARY_DIRECTORY_BOOT_DELAY_DEFAULT_MS = 5 * 60 * 1000;
115 
116     // The longest amount of time that we will retain a queued result and continue retrying to
117     // deliver it. After this amount of time the result will be discarded.
118     @VisibleForTesting
119     public static final int QUEUED_RESULT_MAX_RETAINED_DURATION_MS = 7 * 24 * 60 * 60 * 1000;
120 
121     private static final int PERSIST_TO_DISK_DEFAULT_FREQUENCY_MS = 30 * 60 * 1000;
122 
123     // Targeting a period of around 24 hours, so set max and min to 24 +/- 6 hours, respectively.
124     private static final int DEFAULT_SYSTEM_TRIGGERED_TRACE_MIN_PERIOD_SECONDS = 18 * 60 * 60;
125     private static final int DEFAULT_SYSTEM_TRIGGERED_TRACE_MAX_PERIOD_SECONDS = 30 * 60 * 60;
126 
127     private final Context mContext;
128     private final Object mLock = new Object();
129     private final HandlerThread mHandlerThread = new HandlerThread("ProfilingService");
130 
131     @VisibleForTesting public RateLimiter mRateLimiter = null;
132 
133     // Timeout for Perfetto process to successfully stop after we try to stop it.
134     private int mPerfettoDestroyTimeoutMs;
135     private int mMaxResultRedeliveryCount;
136     private int mProfilingRecheckDelayMs;
137 
138     @GuardedBy("mLock")
139     private long mLastClearTemporaryDirectoryTimeMs = 0;
140     private int mClearTemporaryDirectoryFrequencyMs;
141     private final int mClearTemporaryDirectoryBootDelayMs;
142 
143     private int mRedactionCheckFrequencyMs;
144     private int mRedactionMaxRuntimeAllottedMs;
145 
146     private Handler mHandler;
147 
148     private Calendar mCalendar = null;
149     private SimpleDateFormat mDateFormat = null;
150 
151     // uid indexed collection of lists of callbacks for results.
152     @VisibleForTesting
153     public SparseArray<List<IProfilingResultCallback>> mResultCallbacks = new SparseArray<>();
154 
155     // Request UUID key indexed storage of active tracing sessions. Currently only 1 active session
156     // is supported at a time, but this will be used in future to support multiple.
157     @VisibleForTesting
158     public ArrayMap<String, TracingSession> mActiveTracingSessions = new ArrayMap<>();
159 
160     // System triggered trace is another actively running profiling session, but not included in
161     // the active sessions above as it's not associated with a TracingSession until it has been
162     // cloned.
163     @VisibleForTesting
164     @GuardedBy("mLock")
165     public Process mSystemTriggeredTraceProcess = null;
166     @VisibleForTesting
167     public String mSystemTriggeredTraceUniqueSessionName = null;
168     private long mLastStartedSystemTriggeredTraceMs = 0;
169 
170     // Map of uid + package name to a sparse array of trigger objects.
171     @VisibleForTesting
172     public ProcessMap<SparseArray<ProfilingTriggerData>> mAppTriggers = new ProcessMap<>();
173     @VisibleForTesting
174     public boolean mAppTriggersLoaded = false;
175 
176     // uid indexed storage of completed tracing sessions that have not yet successfully handled the
177     // result.
178     @VisibleForTesting
179     public SparseArray<List<TracingSession>> mQueuedTracingResults = new SparseArray<>();
180 
181     private boolean mPersistScheduled = false;
182     // Frequency of 0 would result in immediate persist.
183     @GuardedBy("mLock")
184     private AtomicInteger mPersistFrequencyMs;
185     @GuardedBy("mLock")
186     private long mLastPersistedTimestampMs = 0L;
187     private Runnable mPersistRunnable = null;
188 
189     /** The path to the directory which includes all persisted results from this class. */
190     @VisibleForTesting
191     public File mPersistStoreDir = null;
192 
193     /** The queued results data file, persisted in the storage. */
194     @VisibleForTesting
195     public File mPersistQueueFile = null;
196 
197     /** The app triggers results data file, persisted in the storage. */
198     @VisibleForTesting
199     public File mPersistAppTriggersFile = null;
200 
201     /** To be disabled for testing only. */
202     @GuardedBy("mLock")
203     private boolean mKeepResultInTempDir = false;
204 
205     /** Executor for scheduling system triggered profiling trace. */
206     private ScheduledExecutorService mScheduledExecutorService = null;
207 
208     /** Future for the start system triggered trace. */
209     @VisibleForTesting
210     public ScheduledFuture<?> mStartSystemTriggeredTraceScheduledFuture = null;
211 
212     @GuardedBy("mLock")
213     private AtomicInteger mSystemTriggeredTraceMinPeriodSeconds;
214     @GuardedBy("mLock")
215     private AtomicInteger mSystemTriggeredTraceMaxPeriodSeconds;
216 
217     /**
218      * Package name of app being tested, or null if no app is being tested. To be used both for
219      * automated testing and developer manual testing.
220      *
221      * Setting this package name will:
222      * - Ensure a system triggered trace is always running.
223      * - Allow all triggers for the specified package name to be executed.
224      *
225      * This is not intended to be set directly. Instead, set this package name by using
226      * device_config commands described at {@link ProfilingManager}.
227      *
228      * There is no time limit on how long this can be left enabled for.
229      */
230     private String mTestPackageName = null;
231 
232     /**
233      * State the {@link TracingSession} is in.
234      *
235      * State represents the most recently confirmed completed step in the process. Steps represent
236      * save points which the process would have to go back to if it did not successfully reach the
237      * next step.
238      *
239      * States are sequential. It can be expected that state value will only increase throughout a
240      * sessions life.
241      *
242      * At different states, the containing object can be assumed to exist in different data
243      * structures as follows:
244      * REQUESTED - Local only, not in any data structure.
245      * APPROVED - Local only, not in any data structure.
246      * PROFILING_STARTED - Stored in {@link mActiveTracingSessions}.
247      * PROFILING_FINISHED - Stored in {@link mQueuedTracingResults}.
248      * REDACTED - Stored in {@link mQueuedTracingResults}.
249      * COPIED_FILE - Stored in {@link mQueuedTracingResults}.
250      * ERROR_OCCURRED - Stored in {@link mQueuedTracingResults}.
251      * NOTIFIED_REQUESTER - Stored in {@link mQueuedTracingResults}.
252      * CLEANED_UP - Local only, not in any data structure.
253      */
254     public enum TracingState {
255         // Intentionally skipping 0 since proto, which will be used for persist, treats it as unset.
256         REQUESTED(1),
257         APPROVED(2),
258         PROFILING_STARTED(3),
259         PROFILING_FINISHED(4),
260         REDACTED(5),
261         COPIED_FILE(6),
262         ERROR_OCCURRED(7),
263         NOTIFIED_REQUESTER(8),
264         CLEANED_UP(9);
265 
266         /** Data structure for efficiently mapping int values back to their enum values. */
267         private static List<TracingState> sStatesList;
268 
269         static {
270             sStatesList = Arrays.asList(TracingState.values());
271         }
272 
273         private final int mValue;
TracingState(int value)274         TracingState(int value) {
275             mValue = value;
276         }
277 
278         /** Obtain TracingState from int value. */
of(int value)279         public static TracingState of(int value) {
280             if (value < 1 || value >= sStatesList.size() + 1) {
281                 return null;
282             }
283 
284             return sStatesList.get(value - 1);
285         }
286 
getValue()287         public int getValue() {
288             return mValue;
289         }
290     }
291 
292     @VisibleForTesting
ProfilingService(Context context)293     public ProfilingService(Context context) {
294         mContext = context;
295 
296         mPerfettoDestroyTimeoutMs = DeviceConfigHelper.getInt(
297                 DeviceConfigHelper.PERFETTO_DESTROY_TIMEOUT_MS,
298                 PERFETTO_DESTROY_DEFAULT_TIMEOUT_MS);
299 
300         mMaxResultRedeliveryCount = DeviceConfigHelper.getInt(
301                 DeviceConfigHelper.MAX_RESULT_REDELIVERY_COUNT,
302                 DEFAULT_MAX_RESULT_REDELIVERY_COUNT);
303 
304         mProfilingRecheckDelayMs = DeviceConfigHelper.getInt(
305                 DeviceConfigHelper.PROFILING_RECHECK_DELAY_MS,
306                 PROFILING_DEFAULT_RECHECK_DELAY_MS);
307 
308         mClearTemporaryDirectoryFrequencyMs = DeviceConfigHelper.getInt(
309                 DeviceConfigHelper.CLEAR_TEMPORARY_DIRECTORY_FREQUENCY_MS,
310                 CLEAR_TEMPORARY_DIRECTORY_FREQUENCY_DEFAULT_MS);
311 
312         mClearTemporaryDirectoryBootDelayMs = DeviceConfigHelper.getInt(
313                 DeviceConfigHelper.CLEAR_TEMPORARY_DIRECTORY_BOOT_DELAY_MS,
314             CLEAR_TEMPORARY_DIRECTORY_BOOT_DELAY_DEFAULT_MS);
315 
316         mRedactionCheckFrequencyMs = DeviceConfigHelper.getInt(
317                 DeviceConfigHelper.REDACTION_CHECK_FREQUENCY_MS,
318                 REDACTION_DEFAULT_CHECK_FREQUENCY_MS);
319 
320         mRedactionMaxRuntimeAllottedMs = DeviceConfigHelper.getInt(
321                 DeviceConfigHelper.REDACTION_MAX_RUNTIME_ALLOTTED_MS,
322                 REDACTION_DEFAULT_MAX_RUNTIME_ALLOTTED_MS);
323 
324         mHandlerThread.start();
325 
326         // Get initial value for whether unredacted trace should be retained.
327         // This is used for (automated and manual) testing only.
328         synchronized (mLock) {
329             mKeepResultInTempDir = DeviceConfigHelper.getTestBoolean(
330                     DeviceConfigHelper.DISABLE_DELETE_TEMPORARY_RESULTS, false);
331 
332             mPersistFrequencyMs = new AtomicInteger(DeviceConfigHelper.getInt(
333                     DeviceConfigHelper.PERSIST_TO_DISK_FREQUENCY_MS,
334                     PERSIST_TO_DISK_DEFAULT_FREQUENCY_MS));
335 
336             mSystemTriggeredTraceMinPeriodSeconds = new AtomicInteger(DeviceConfigHelper.getInt(
337                     DeviceConfigHelper.SYSTEM_TRIGGERED_TRACE_MIN_PERIOD_SECONDS,
338                     DEFAULT_SYSTEM_TRIGGERED_TRACE_MIN_PERIOD_SECONDS));
339 
340             mSystemTriggeredTraceMaxPeriodSeconds = new AtomicInteger(DeviceConfigHelper.getInt(
341                     DeviceConfigHelper.SYSTEM_TRIGGERED_TRACE_MAX_PERIOD_SECONDS,
342                     DEFAULT_SYSTEM_TRIGGERED_TRACE_MAX_PERIOD_SECONDS));
343         }
344         // Now subscribe to updates on test config.
345         DeviceConfig.addOnPropertiesChangedListener(DeviceConfigHelper.NAMESPACE_TESTING,
346                 mContext.getMainExecutor(), new DeviceConfig.OnPropertiesChangedListener() {
347                     @Override
348                     public void onPropertiesChanged(@NonNull DeviceConfig.Properties properties) {
349                         synchronized (mLock) {
350                             mKeepResultInTempDir = properties.getBoolean(
351                                     DeviceConfigHelper.DISABLE_DELETE_TEMPORARY_RESULTS, false);
352                             getRateLimiter().maybeUpdateRateLimiterDisabled(properties);
353 
354                             String newTestPackageName = properties.getString(
355                                     DeviceConfigHelper.SYSTEM_TRIGGERED_TEST_PACKAGE_NAME, null);
356                             handleTestPackageChangeLocked(newTestPackageName);
357                         }
358                     }
359                 });
360 
361         // Subscribe to updates on the main config.
362         DeviceConfig.addOnPropertiesChangedListener(DeviceConfigHelper.NAMESPACE,
363                 mContext.getMainExecutor(), new DeviceConfig.OnPropertiesChangedListener() {
364                     @Override
365                     public void onPropertiesChanged(@NonNull DeviceConfig.Properties properties) {
366                         synchronized (mLock) {
367                             getRateLimiter().maybeUpdateConfigs(properties);
368                             Configs.maybeUpdateConfigs(properties);
369 
370                             mPerfettoDestroyTimeoutMs = properties.getInt(
371                                     DeviceConfigHelper.PERFETTO_DESTROY_TIMEOUT_MS,
372                                     mPerfettoDestroyTimeoutMs);
373 
374                             mMaxResultRedeliveryCount = properties.getInt(
375                                     DeviceConfigHelper.MAX_RESULT_REDELIVERY_COUNT,
376                                     mMaxResultRedeliveryCount);
377 
378                             mProfilingRecheckDelayMs = properties.getInt(
379                                     DeviceConfigHelper.PROFILING_RECHECK_DELAY_MS,
380                                     mProfilingRecheckDelayMs);
381 
382                             mClearTemporaryDirectoryFrequencyMs = properties.getInt(
383                                     DeviceConfigHelper.CLEAR_TEMPORARY_DIRECTORY_FREQUENCY_MS,
384                                     mClearTemporaryDirectoryFrequencyMs);
385 
386                             // No need to handle updates for
387                             // {@link mClearTemporaryDirectoryBootDelayMs} as it's only used on
388                             // initialization of this class so by the time this occurs it will never
389                             // be used again.
390 
391                             mRedactionCheckFrequencyMs = properties.getInt(
392                                     DeviceConfigHelper.REDACTION_CHECK_FREQUENCY_MS,
393                                     mRedactionCheckFrequencyMs);
394 
395                             mRedactionMaxRuntimeAllottedMs = properties.getInt(
396                                     DeviceConfigHelper.REDACTION_MAX_RUNTIME_ALLOTTED_MS,
397                                     mRedactionMaxRuntimeAllottedMs);
398 
399                             mPersistFrequencyMs.set(properties.getInt(
400                                     DeviceConfigHelper.PERSIST_TO_DISK_FREQUENCY_MS,
401                                     mPersistFrequencyMs.get()));
402 
403                             mSystemTriggeredTraceMinPeriodSeconds.set(DeviceConfigHelper.getInt(
404                                     DeviceConfigHelper.SYSTEM_TRIGGERED_TRACE_MIN_PERIOD_SECONDS,
405                                     mSystemTriggeredTraceMinPeriodSeconds.get()));
406 
407                             mSystemTriggeredTraceMaxPeriodSeconds.set(DeviceConfigHelper.getInt(
408                                     DeviceConfigHelper.SYSTEM_TRIGGERED_TRACE_MAX_PERIOD_SECONDS,
409                                     mSystemTriggeredTraceMaxPeriodSeconds.get()));
410                         }
411                     }
412                 });
413 
414         // Schedule initial storage cleanup and system triggered trace start after a delay so as not
415         // to increase non-critical or work during boot.
416         getHandler().postDelayed(new Runnable() {
417             @Override
418             public void run() {
419                 scheduleNextSystemTriggeredTraceStart();
420                 maybeCleanupTemporaryDirectory();
421             }
422         }, mClearTemporaryDirectoryBootDelayMs);
423 
424         // Load the queue and triggers right away.
425         loadQueueFromPersistedData();
426         loadAppTriggersFromPersistedData();
427     }
428 
429     /**
430      * Load persisted queue entries. If any issue is encountered reading/parsing the file, delete it
431      * and return as failure to load queue does not block the feature.
432      */
433     @VisibleForTesting
loadQueueFromPersistedData()434     public void loadQueueFromPersistedData() {
435         if (!Flags.persistQueue()) {
436             return;
437         }
438 
439         // Setup persist files
440         try {
441             if (!setupPersistQueueFiles()) {
442                 // If setting up the directory and file was unsuccessful then just return. Past and
443                 // future queued results will be lost, but the feature as a whole still works.
444                 if (DEBUG) Log.d(TAG, "Failed to setup queue persistence directory/files.");
445                 return;
446             }
447         } catch (SecurityException e) {
448             // Can't access files.
449             if (DEBUG) Log.e(TAG, "Failed to setup queue persistence directory/files.", e);
450             return;
451         }
452 
453         // Check if file exists
454         try {
455             if (!mPersistQueueFile.exists()) {
456                 // No file, nothing to load. This is an expected state for before the feature has
457                 // ever been used or if the queue was emptied.
458                 if (DEBUG) {
459                     Log.d(TAG, "Queue persistence file does not exist, skipping load from disk.");
460                 }
461                 return;
462             }
463         } catch (SecurityException e) {
464             // Can't access file.
465             if (DEBUG) Log.e(TAG, "Exception accessing queue persistence file", e);
466             return;
467         }
468 
469         // Read the file
470         AtomicFile persistFile = new AtomicFile(mPersistQueueFile);
471         byte[] bytes;
472         try {
473             bytes = persistFile.readFully();
474         } catch (IOException e) {
475             if (DEBUG) Log.e(TAG, "Exception reading queue persistence file", e);
476             // Failed to read the file. No reason to believe we'll have better luck next time,
477             // delete the file and return. Results in the queue will be lost.
478             deletePersistQueueFile();
479             return;
480         }
481         if (bytes.length == 0) {
482             if (DEBUG) Log.d(TAG, "Queue persistence file is empty, skipping load from disk.");
483             // Empty queue persist file. Delete the file and return.
484             deletePersistQueueFile();
485             return;
486         }
487 
488         // Parse file bytes to proto
489         QueuedResultsWrapper wrapper;
490         try {
491             wrapper = QueuedResultsWrapper.parseFrom(bytes);
492         } catch (Exception e) {
493             if (DEBUG) Log.e(TAG, "Error parsing proto from persisted bytes", e);
494             // Failed to parse the file contents. No reason to believe we'll have better luck next
495             // time, delete the file and return. Results in the queue will be lost.
496             deletePersistQueueFile();
497             return;
498         }
499 
500         // Populate in memory records store
501         for (int i = 0; i < wrapper.getSessionsCount(); i++) {
502             QueuedResultsWrapper.TracingSession sessionsProto = wrapper.getSessions(i);
503             TracingSession session = new TracingSession(sessionsProto);
504             // Since we're populating the in memory store from the persisted queue we don't want to
505             // trigger a persist, so pass param false. If we did trigger the persist from here, it
506             // would overwrite the file with the first record only and then queue the remaining
507             // records for later, thereby leaving the persisted queue with less data than it
508             // currently contains and potentially leading to lost data in event of shutdown before
509             // the scheduled persist occurs.
510             moveSessionToQueue(session, false);
511         }
512     }
513 
514     /**
515      * Load persisted app triggers from disk.
516      *
517      * If any issue is encountered during loading, mark as completed and delete the file. Persisted
518      * app triggers will be lost.
519      */
520     @VisibleForTesting
loadAppTriggersFromPersistedData()521     public void loadAppTriggersFromPersistedData() {
522         // Setup persist files
523         try {
524             if (!setupPersistAppTriggerFiles()) {
525                 // If setting up the directory and file was unsuccessful then just return without
526                 // marking loaded so it can be tried again.
527                 if (DEBUG) Log.d(TAG, "Failed to setup app trigger persistence directory/files.");
528                 return;
529             }
530         } catch (SecurityException e) {
531             // Can't access files.
532             Log.w(TAG, "Failed to setup app trigger persistence directory/files.", e);
533             return;
534         }
535 
536         // Check if file exists
537         try {
538             if (!mPersistAppTriggersFile.exists()) {
539                 // No file, nothing to load. This is an expected state for before the feature has
540                 // ever been used or if the triggers were empty.
541                 if (DEBUG) {
542                     Log.d(TAG, "App trigger persistence file does not exist, skipping load from "
543                             + "disk.");
544                 }
545                 mAppTriggersLoaded = true;
546                 return;
547             }
548         } catch (SecurityException e) {
549             // Can't access file.
550             if (DEBUG) Log.e(TAG, "Exception accessing app triggers persistence file", e);
551             return;
552         }
553 
554         // Read the file
555         AtomicFile persistFile = new AtomicFile(mPersistAppTriggersFile);
556         byte[] bytes;
557         try {
558             bytes = persistFile.readFully();
559         } catch (IOException e) {
560             Log.w(TAG, "Exception reading app triggers persistence file", e);
561             // Failed to read the file. No reason to believe we'll have better luck next time,
562             // delete the file and return. Persisted triggers will be lost until the app re-adds
563             // them.
564             deletePersistAppTriggersFile();
565             mAppTriggersLoaded = true;
566             return;
567         }
568         if (bytes.length == 0) {
569             if (DEBUG) Log.d(TAG, "App triggers persistence file empty, skipping load from disk.");
570             // Empty app triggers persist file. Delete the file, mark loaded, and return.
571             deletePersistAppTriggersFile();
572             mAppTriggersLoaded = true;
573             return;
574         }
575 
576         // Parse file bytes to proto
577         ProfilingTriggersWrapper wrapper;
578         try {
579             wrapper = ProfilingTriggersWrapper.parseFrom(bytes);
580         } catch (Exception e) {
581             Log.w(TAG, "Error parsing proto from persisted bytes", e);
582             // Failed to parse the file contents. No reason to believe we'll have better luck next
583             // time, delete the file, mark loaded, and return. Persisted app triggers will be lost
584             // until re-added by the app.
585             deletePersistAppTriggersFile();
586             mAppTriggersLoaded = true;
587             return;
588         }
589 
590         // Populate in memory app triggers store
591         for (int i = 0; i < wrapper.getTriggersCount(); i++) {
592             ProfilingTriggersWrapper.ProfilingTrigger triggerProto = wrapper.getTriggers(i);
593             addTrigger(new ProfilingTriggerData(triggerProto), false);
594         }
595 
596         mAppTriggersLoaded = true;
597     }
598 
599     /** Setup the directory and file for persisting queue. */
600     @VisibleForTesting
setupPersistQueueFiles()601     public boolean setupPersistQueueFiles() {
602         if (mPersistStoreDir == null) {
603             if (!setupPersistDir()) {
604                 return false;
605             }
606         }
607         mPersistQueueFile = new File(mPersistStoreDir, QUEUED_RESULTS_INFO_FILE);
608         return true;
609     }
610 
611     /** Setup the directory and file for persisting app triggers. */
612     @VisibleForTesting
setupPersistAppTriggerFiles()613     public boolean setupPersistAppTriggerFiles() {
614         if (mPersistStoreDir == null) {
615             if (!setupPersistDir()) {
616                 return false;
617             }
618         }
619         mPersistAppTriggersFile = new File(mPersistStoreDir, APP_TRIGGERS_INFO_FILE);
620         return true;
621     }
622 
623     /** Setup the directory and file for persisting. */
624     @VisibleForTesting
setupPersistDir()625     public boolean setupPersistDir() {
626         File dataDir = Environment.getDataDirectory();
627         File systemDir = new File(dataDir, PERSIST_SYSTEM_DIR);
628         mPersistStoreDir = new File(systemDir, PERSIST_STORE_DIR);
629         return createDir(mPersistStoreDir);
630     }
631 
632     /** Delete the persist queue file. */
633     @VisibleForTesting
deletePersistQueueFile()634     public void deletePersistQueueFile() {
635         try {
636             mPersistQueueFile.delete();
637             if (DEBUG) Log.d(TAG, "Deleted queue persist file.");
638         } catch (SecurityException e) {
639             // Can't delete file.
640             if (DEBUG) Log.d(TAG, "Failed to delete queue persist file", e);
641         }
642     }
643 
644     /** Delete the persist app triggers file. */
645     @VisibleForTesting
deletePersistAppTriggersFile()646     public void deletePersistAppTriggersFile() {
647         try {
648             mPersistAppTriggersFile.delete();
649             if (DEBUG) Log.d(TAG, "Deleted app triggers persist file.");
650         } catch (SecurityException e) {
651             // Can't delete file.
652             if (DEBUG) Log.d(TAG, "Failed to delete app triggers persist file", e);
653         }
654     }
655 
createDir(File dir)656     private static boolean createDir(File dir) throws SecurityException {
657         if (dir.mkdir()) {
658             return true;
659         }
660 
661         if (dir.exists()) {
662             return dir.isDirectory();
663         }
664 
665         return false;
666     }
667 
668     /**
669      * Schedule the next start of system triggered profiling trace for a random time between min and
670      * max period.
671      */
672     @VisibleForTesting
scheduleNextSystemTriggeredTraceStart()673     public void scheduleNextSystemTriggeredTraceStart() {
674         if (!Flags.systemTriggeredProfilingNew()) {
675             // Feature disabled.
676             return;
677         }
678 
679         if (mStartSystemTriggeredTraceScheduledFuture != null) {
680             // If an existing start is already scheduled, don't schedule another.
681             // This should not happen.
682             Log.e(TAG, "Attempted to schedule a system triggered trace start with one already "
683                     + "scheduled.");
684             return;
685         }
686 
687         if (mScheduledExecutorService == null) {
688             mScheduledExecutorService = Executors.newSingleThreadScheduledExecutor();
689         }
690 
691         int scheduledDelaySeconds;
692 
693         synchronized (mLock) {
694             // It's important that trace doesn't always run at the same time as this will bias the
695             // results, so grab a random number between min and max.
696             scheduledDelaySeconds = mSystemTriggeredTraceMinPeriodSeconds.get()
697                     + (new Random()).nextInt(mSystemTriggeredTraceMaxPeriodSeconds.get()
698                     - mSystemTriggeredTraceMinPeriodSeconds.get());
699 
700             if (DEBUG) {
701                 Log.d(TAG, String.format("System triggered trace scheduled in %d seconds for params"
702                         + " min %d and max %d seconds.",
703                         scheduledDelaySeconds,
704                         mSystemTriggeredTraceMinPeriodSeconds.get(),
705                         mSystemTriggeredTraceMaxPeriodSeconds.get()));
706             }
707         }
708 
709         // Scheduling of system triggered trace setup is done out of the lock to avoid a potential
710         // deadlock in the case of really frequent triggering due to low min/max values for period.
711         mStartSystemTriggeredTraceScheduledFuture = mScheduledExecutorService.schedule(() -> {
712             // Start the system triggered trace.
713             startSystemTriggeredTrace();
714 
715             mStartSystemTriggeredTraceScheduledFuture = null;
716 
717             // In all cases, schedule again. Feature flagged off is handled earlier in this
718             // method, and all return cases in {@link #startSystemTriggeredTrace} should result
719             // in trying again at the next regularly scheduled time.
720             scheduleNextSystemTriggeredTraceStart();
721         }, scheduledDelaySeconds, TimeUnit.SECONDS);
722     }
723 
724     /**
725      * This is the core method that keeps the profiling flow moving.
726      *
727      * This is the only way that state should be set. Do not use {@link TracingSession#setState}
728      * directly.
729      *
730      * The passed newState represents the state that was just completed. Passing null for new state
731      * will continue using the current state as the last completed state, this is intended only for
732      * resuming the queue.
733      *
734      * Generally, this should be the last call in a method before returning.
735      */
736     @VisibleForTesting
advanceTracingSession(TracingSession session, @Nullable TracingState newState)737     public void advanceTracingSession(TracingSession session, @Nullable TracingState newState) {
738         if (newState == null) {
739             if (session.getRetryCount() == 0) {
740                 // The new state should only be null if this is triggered from the queue in which
741                 // case the retry count should be greater than 0. If retry count is 0 here then
742                 // we're in an unexpected state. Cleanup and discard. Result will be lost.
743                 cleanupTracingSession(session);
744                 return;
745             }
746         } else if (newState == session.getState()) {
747             // This should never happen.
748             // If the state is not actually changing then we may find ourselves in an infinite
749             // loop. Terminate this attempt and increment the retry count to ensure there's a
750             // path to breaking out of a potential infinite queue retries.
751             session.incrementRetryCount();
752             return;
753         } else if (newState.getValue() < session.getState().getValue()) {
754             // This should also never happen.
755             // States should always move forward. If the state is trying to move backwards then
756             // we don't actually know what to do next. Clean up the session and delete
757             // everything. Results will be lost.
758             cleanupTracingSession(session);
759             return;
760         } else {
761             // The new state is not null so update the sessions state.
762             session.setState(newState);
763         }
764 
765         switch (session.getState()) {
766             case REQUESTED:
767                 // This should never happen as requested state is expected to handled by the request
768                 // method, the first actionable state is approved. Ignore it.
769                 if (DEBUG) {
770                     Log.e(TAG, "Session attempting to advance with REQUESTED state unsupported.");
771                 }
772                 break;
773             case APPROVED:
774                 // Session has been approved by rate limiter, so continue on to start profiling.
775                 startProfiling(session);
776                 break;
777             case PROFILING_STARTED:
778                 // Profiling has been successfully started. Next step depends on whether or not the
779                 // profiling is alive.
780                 if (session.getActiveTrace() == null || !session.getActiveTrace().isAlive()
781                         || session.getProcessResultRunnable() == null) {
782                     // This really should not happen, but if profiling is not in correct started
783                     // state then try to stop and continue processing it.
784                     stopProfiling(session);
785                 } // else: do nothing. The runnable we just verified exists will return us to this
786                 // method when profiling is finished.
787                 break;
788             case PROFILING_FINISHED:
789                 // Next step depends on whether or not the result requires redaction.
790                 if (needsRedaction(session)) {
791                     // Redaction needed, kick it off.
792                     handleRedactionRequiredResult(session);
793                 } else {
794                     // For results that don't require redaction, maybe log the location of the
795                     // retained result after profiling completes.
796                     handleRetainedTempFiles(session);
797 
798                     // No redaction needed, move straight to copying to app storage.
799                     beginMoveFileToAppStorage(session);
800                 }
801                 break;
802             case REDACTED:
803                 // For results that require redaction, maybe log the location of the retained result
804                 // after redaction completes.
805                 handleRetainedTempFiles(session);
806 
807                 // Redaction completed, move on to copying to app storage.
808                 beginMoveFileToAppStorage(session);
809                 break;
810             case COPIED_FILE:
811                 // File has already been copied to app storage, proceed to callback.
812                 session.setError(ProfilingResult.ERROR_NONE);
813                 processTracingSessionResultCallback(session, true /* Continue advancing session */);
814 
815                 // This is a good place to persist the queue if possible because the processing work
816                 // is complete and we tried to send a callback to the app. If the callback
817                 // succeeded, then we will already have recursed on this method with new state of
818                 // NOTIFIED_REQUESTER and the only potential remaining work to be repeated will be
819                 // cleanup. If the callback failed, then we won't have recursed here and we'll pick
820                 // back up this stage next time thereby minimizing repeated work.
821                 maybePersistToDisk();
822                 break;
823             case ERROR_OCCURRED:
824                 // An error has occurred, proceed to callback.
825                 processTracingSessionResultCallback(session, true /* Continue advancing session */);
826 
827                 // This is a good place to persist the queue if possible because the processing work
828                 // is complete and we tried to send a callback to the app. If the callback
829                 // succeeded, then we will already have recursed on this method with new state of
830                 // NOTIFIED_REQUESTER and the only potential remaining work to be repeated will be
831                 // cleanup. If the callback failed, then we won't have recursed here and we'll pick
832                 // back up this stage next time thereby minimizing repeated work.
833                 maybePersistToDisk();
834                 break;
835             case NOTIFIED_REQUESTER:
836                 // Callback has been completed successfully, start cleanup.
837                 cleanupTracingSession(session);
838                 break;
839             case CLEANED_UP:
840                 // Session was cleaned up, nothing left to do.
841                 break;
842         }
843     }
844 
845     /** Perform a temporary directory cleanup if it has been long enough to warrant one. */
maybeCleanupTemporaryDirectory()846     private void maybeCleanupTemporaryDirectory() {
847         synchronized (mLock) {
848             if (mLastClearTemporaryDirectoryTimeMs + mClearTemporaryDirectoryFrequencyMs
849                     < System.currentTimeMillis()) {
850                 cleanupTemporaryDirectoryLocked(TEMP_TRACE_PATH);
851             }
852         }
853     }
854 
855 
856     /** Cleanup untracked data stored in provided directory. */
857     @GuardedBy("mLock")
858     @VisibleForTesting
cleanupTemporaryDirectoryLocked(String temporaryDirectoryPath)859     public void cleanupTemporaryDirectoryLocked(String temporaryDirectoryPath) {
860         if (mKeepResultInTempDir) {
861             // Don't clean up any temporary files while {@link mKeepResultInTempDir} is enabled as
862             // files are being retained for testing purposes.
863             return;
864         }
865 
866         // Obtain a list of all currently tracked files and create a filter with it. Filter is set
867         // to null if the list is empty as that will efficiently accept all files.
868         final List<String> trackedFilenames = getTrackedFilenames();
869         FilenameFilter filenameFilter = trackedFilenames.isEmpty() ? null : new FilenameFilter() {
870             @Override
871             public boolean accept(File dir, String name) {
872                 // We only want to accept files which are not in the tracked files list.
873                 return !trackedFilenames.contains(name);
874             }
875         };
876 
877         // Now obtain a list of files in the provided directory that are not tracked.
878         File directory = new File(temporaryDirectoryPath);
879         File[] files = null;
880         try {
881             files = directory.listFiles(filenameFilter);
882         } catch (SecurityException e) {
883             // Couldn't get a list of files, can't cleanup anything.
884             if (DEBUG) {
885                 Log.d(TAG, "Failed to get file list from temporary directory. Cleanup aborted.", e);
886             }
887             return;
888         }
889 
890         if (files == null) {
891             // The path doesn't exist or an I/O error occurred.
892             if (DEBUG) {
893                 Log.d(TAG, "Temporary directory doesn't exist or i/o error occurred. "
894                         + "Cleanup aborted.");
895             }
896             return;
897         }
898 
899         // Set time here as we'll either return due to no files or attempt to delete files, after
900         // either of which we should wait before checking again.
901         mLastClearTemporaryDirectoryTimeMs = System.currentTimeMillis();
902 
903         if (files.length == 0) {
904             // No files, nothing to cleanup.
905             if (DEBUG) Log.d(TAG, "No files in temporary directory to cleanup.");
906             return;
907         }
908 
909         // Iterate through and delete them.
910         for (int i = 0; i < files.length; i++) {
911             try {
912                 files[i].delete();
913             } catch (SecurityException e) {
914                 // Exception deleting file, keep trying for the others.
915                 if (DEBUG) Log.d(TAG, "Exception deleting file from temp directory.", e);
916             }
917         }
918     }
919 
920     /**
921      * Return a list of all filenames that are currently tracked in either the in progress
922      * collections or the queued results, including both redacted and unredacted.
923      */
getTrackedFilenames()924     private List<String> getTrackedFilenames() {
925         List<String> filenames = new ArrayList<String>();
926 
927         // If active sessions is not empty, iterate through and add the filenames from each.
928         if (!mActiveTracingSessions.isEmpty()) {
929             for (int i = 0; i < mActiveTracingSessions.size(); i++) {
930                 TracingSession session = mActiveTracingSessions.valueAt(i);
931                 String filename = session.getFileName();
932                 if (filename != null) {
933                     filenames.add(filename);
934                 }
935                 String redactedFilename = session.getRedactedFileName();
936                 if (redactedFilename != null) {
937                     filenames.add(redactedFilename);
938                 }
939             }
940         }
941 
942         // If queued sessions is not empty, iterate through and add the filenames from each.
943         if (mQueuedTracingResults.size() != 0) {
944             for (int i = 0; i < mQueuedTracingResults.size(); i++) {
945                 List<TracingSession> perUidSessions = mQueuedTracingResults.valueAt(i);
946                 if (!perUidSessions.isEmpty()) {
947                     for (int j = 0; j < perUidSessions.size(); j++) {
948                         TracingSession session = perUidSessions.get(j);
949                         String filename = session.getFileName();
950                         if (filename != null) {
951                             filenames.add(filename);
952                         }
953                         String redactedFilename = session.getRedactedFileName();
954                         if (redactedFilename != null) {
955                             filenames.add(redactedFilename);
956                         }
957                     }
958                 }
959             }
960         }
961 
962         return filenames;
963     }
964 
965     /**
966      * This method validates the request, arguments, whether the app is allowed to profile now,
967      * and if so, starts the profiling.
968      */
requestProfiling(int profilingType, Bundle params, String tag, long keyMostSigBits, long keyLeastSigBits, String packageName)969     public void requestProfiling(int profilingType, Bundle params, String tag,
970             long keyMostSigBits, long keyLeastSigBits, String packageName) {
971         int uid = Binder.getCallingUid();
972 
973         if (profilingType != ProfilingManager.PROFILING_TYPE_JAVA_HEAP_DUMP
974                 && profilingType != ProfilingManager.PROFILING_TYPE_HEAP_PROFILE
975                 && profilingType != ProfilingManager.PROFILING_TYPE_STACK_SAMPLING
976                 && profilingType != ProfilingManager.PROFILING_TYPE_SYSTEM_TRACE) {
977             if (DEBUG) Log.d(TAG, "Invalid request profiling type: " + profilingType);
978             processResultCallback(uid, keyMostSigBits, keyLeastSigBits,
979                     ProfilingResult.ERROR_FAILED_INVALID_REQUEST, null, tag,
980                     "Invalid request profiling type", getTriggerTypeNone());
981             return;
982         }
983 
984         cleanupActiveTracingSessions();
985 
986         // Check if we're running another trace so we don't run multiple at once.
987         try {
988             if (areAnyTracesRunning()) {
989                 processResultCallback(uid, keyMostSigBits, keyLeastSigBits,
990                         ProfilingResult.ERROR_FAILED_PROFILING_IN_PROGRESS, null, tag, null,
991                         getTriggerTypeNone());
992                 return;
993             }
994         } catch (RuntimeException e) {
995             if (DEBUG) Log.d(TAG, "Error communicating with perfetto", e);
996             processResultCallback(uid, keyMostSigBits, keyLeastSigBits,
997                     ProfilingResult.ERROR_UNKNOWN, null, tag, "Error communicating with perfetto",
998                     getTriggerTypeNone());
999             return;
1000         }
1001 
1002         if (packageName == null) {
1003             // This shouldn't happen as it should be checked on the app side.
1004             if (DEBUG) Log.d(TAG, "PackageName is null");
1005             processResultCallback(uid, keyMostSigBits, keyLeastSigBits,
1006                     ProfilingResult.ERROR_UNKNOWN, null, tag, "Couldn't determine package name",
1007                     getTriggerTypeNone());
1008             return;
1009         }
1010 
1011         String[] uidPackages = mContext.getPackageManager().getPackagesForUid(uid);
1012         if (uidPackages == null || uidPackages.length == 0) {
1013             // Failed to get uids for this package, can't validate package name.
1014             if (DEBUG) Log.d(TAG, "Failed to resolve package name");
1015             processResultCallback(uid, keyMostSigBits, keyLeastSigBits,
1016                     ProfilingResult.ERROR_UNKNOWN, null, tag, "Couldn't determine package name",
1017                     getTriggerTypeNone());
1018             return;
1019         }
1020 
1021         boolean packageNameInUidList = false;
1022         for (int i = 0; i < uidPackages.length; i++) {
1023             if (packageName.equals(uidPackages[i])) {
1024                 packageNameInUidList = true;
1025                 break;
1026             }
1027         }
1028         if (!packageNameInUidList) {
1029             // Package name is not associated with calling uid, reject request.
1030             if (DEBUG) Log.d(TAG, "Package name not associated with calling uid");
1031             processResultCallback(uid, keyMostSigBits, keyLeastSigBits,
1032                     ProfilingResult.ERROR_FAILED_INVALID_REQUEST, null, tag,
1033                     "Package name not associated with calling uid.", getTriggerTypeNone());
1034             return;
1035         }
1036 
1037         // Check with rate limiter if this request is allowed.
1038         final int status = getRateLimiter().isProfilingRequestAllowed(Binder.getCallingUid(),
1039                 profilingType, false, params);
1040         if (DEBUG) Log.d(TAG, "Rate limiter status: " + status);
1041         if (status == RateLimiter.RATE_LIMIT_RESULT_ALLOWED) {
1042             // Rate limiter approved, try to start the request.
1043             try {
1044                 TracingSession session = new TracingSession(profilingType, params, uid,
1045                         packageName, tag, keyMostSigBits, keyLeastSigBits, getTriggerTypeNone());
1046                 advanceTracingSession(session, TracingState.APPROVED);
1047                 return;
1048             } catch (IllegalArgumentException e) {
1049                 // This should not happen, it should have been caught when checking rate limiter.
1050                 // Issue with the request. Apps fault.
1051                 if (DEBUG) {
1052                     Log.d(TAG,
1053                             "Invalid request at config generation. This should not have happened.",
1054                             e);
1055                 }
1056                 processResultCallback(uid, keyMostSigBits, keyLeastSigBits,
1057                         ProfilingResult.ERROR_FAILED_INVALID_REQUEST, null, tag, e.getMessage(),
1058                         getTriggerTypeNone());
1059                 return;
1060             } catch (RuntimeException e) {
1061                 // Perfetto error. Systems fault.
1062                 if (DEBUG) Log.d(TAG, "Perfetto error", e);
1063                 processResultCallback(uid, keyMostSigBits, keyLeastSigBits,
1064                         ProfilingResult.ERROR_UNKNOWN, null, tag, "Perfetto error",
1065                         getTriggerTypeNone());
1066                 return;
1067             }
1068         } else {
1069             // Rate limiter denied, notify caller.
1070             if (DEBUG) Log.d(TAG, "Request denied with status: " + status);
1071             processResultCallback(uid, keyMostSigBits, keyLeastSigBits,
1072                     RateLimiter.statusToResult(status), null, tag, null, getTriggerTypeNone());
1073         }
1074     }
1075 
1076     /**
1077      * Convenience method to make checking the flag for obtaining trigger type none value in code
1078      * cleaner. When cleaning up the system triggered flag, remove this method and inline the value.
1079      */
getTriggerTypeNone()1080     private int getTriggerTypeNone() {
1081         if (Flags.systemTriggeredProfilingNew()) {
1082             return ProfilingTrigger.TRIGGER_TYPE_NONE;
1083         }
1084         return 0;
1085     }
1086 
1087     /** Call from application to register a callback object. */
registerResultsCallback(boolean isGeneralCallback, IProfilingResultCallback callback)1088     public void registerResultsCallback(boolean isGeneralCallback,
1089             IProfilingResultCallback callback) {
1090         maybeCleanupResultsCallbacks();
1091 
1092         int callingUid = Binder.getCallingUid();
1093         List<IProfilingResultCallback> perUidCallbacks = mResultCallbacks.get(callingUid);
1094         if (perUidCallbacks == null) {
1095             perUidCallbacks = new ArrayList<IProfilingResultCallback>();
1096             mResultCallbacks.put(callingUid, perUidCallbacks);
1097         }
1098         perUidCallbacks.add(callback);
1099 
1100         ProfilingDeathRecipient deathRecipient = new ProfilingDeathRecipient(callingUid);
1101         try {
1102             callback.asBinder().linkToDeath(deathRecipient, 0);
1103         } catch (RemoteException e) {
1104             // Failed to link death recipient. Ignore.
1105             if (DEBUG) Log.d(TAG, "Exception linking death recipient", e);
1106         }
1107 
1108         // Only handle queued results when a new general listener has been added.
1109         if (isGeneralCallback) {
1110             handleQueuedResults(callingUid);
1111         }
1112     }
1113 
1114     /**
1115      * Iterate through and delete any callbacks for which binder is not alive.
1116      *
1117      * Each binder object has a registered linkToDeath which also handles removal. This mechanism
1118      * serves as a backup to guarantee that the list stays in check.
1119      */
maybeCleanupResultsCallbacks()1120     private void maybeCleanupResultsCallbacks() {
1121         // Create a temporary list to hold callbacks to be removed.
1122         ArrayList<IProfilingResultCallback> callbacksToRemove =
1123                 new ArrayList<IProfilingResultCallback>();
1124 
1125         // Iterate through the results callback, each iteration is for a uid which has registered
1126         // callbacks.
1127         for (int i = 0; i < mResultCallbacks.size(); i++) {
1128             // Ensure the temporary list is empty
1129             callbacksToRemove.clear();
1130 
1131             // Grab the current list of callbacks.
1132             List<IProfilingResultCallback> callbacks = mResultCallbacks.valueAt(i);
1133 
1134             if (callbacks != null && !callbacks.isEmpty()) {
1135                 // Now iterate through each of the callbacks for this uid.
1136                 for (int j = 0; j < callbacks.size(); j++) {
1137                     IProfilingResultCallback callback = callbacks.get(j);
1138                     // If the callback is no longer alive, add it to the list for removal.
1139                     if (callback == null || !callback.asBinder().isBinderAlive()) {
1140                         callbacksToRemove.add(callback);
1141                     }
1142                 }
1143 
1144                 // Now remove all the callbacks that were added to the list for removal.
1145                 callbacks.removeAll(callbacksToRemove);
1146             }
1147         }
1148     }
1149 
1150     /**
1151      * Call from application to notify that a new global listener was added and can be accessed
1152      * through the existing callback object.
1153      */
generalListenerAdded()1154     public void generalListenerAdded() {
1155         handleQueuedResults(Binder.getCallingUid());
1156     }
1157 
1158     /**
1159      * Call from application to request the stopping of an active profiling with the provided key.
1160      */
requestCancel(long keyMostSigBits, long keyLeastSigBits)1161     public void requestCancel(long keyMostSigBits, long keyLeastSigBits) {
1162         String key = (new UUID(keyMostSigBits, keyLeastSigBits)).toString();
1163         if (!isTraceRunning(key)) {
1164             // No trace running, nothing to cancel.
1165             if (DEBUG) {
1166                 Log.d(TAG, "Exited requestCancel without stopping trace key:" + key
1167                         + " due to no trace running.");
1168             }
1169             return;
1170         }
1171         stopProfiling(key);
1172     }
1173 
1174     /**
1175      * Add the provided list of validated triggers with the provided package name and the callers
1176      * uid being applied to all.
1177      */
addProfilingTriggers(List<ProfilingTriggerValueParcel> triggers, String packageName)1178     public void addProfilingTriggers(List<ProfilingTriggerValueParcel> triggers,
1179             String packageName) {
1180         int uid = Binder.getCallingUid();
1181         for (int i = 0; i < triggers.size(); i++) {
1182             ProfilingTriggerValueParcel trigger = triggers.get(i);
1183             addTrigger(uid, packageName, trigger.triggerType, trigger.rateLimitingPeriodHours);
1184         }
1185     }
1186 
1187     /**
1188      * Remove the provided list of validated trigger codes from a process with the provided package
1189      * name and the uid of the caller.
1190      */
removeProfilingTriggers(int[] triggerTypesToRemove, String packageName)1191     public void removeProfilingTriggers(int[] triggerTypesToRemove, String packageName) {
1192         SparseArray<ProfilingTriggerData> triggers =
1193                 mAppTriggers.get(packageName, Binder.getCallingUid());
1194 
1195         for (int i = 0; i < triggerTypesToRemove.length; i++) {
1196             int index = triggers.indexOfKey(triggerTypesToRemove[i]);
1197             if (index >= 0) {
1198                 triggers.removeAt(index);
1199             }
1200         }
1201 
1202         if (triggers.size() == 0) {
1203             // Nothing left, remove.
1204             mAppTriggers.remove(packageName, Binder.getCallingUid());
1205         }
1206     }
1207 
1208     /**
1209      * Remove all triggers from a process with the provided packagename and the uid of the caller.
1210      */
clearProfilingTriggers(String packageName)1211     public void clearProfilingTriggers(String packageName) {
1212         mAppTriggers.remove(packageName, Binder.getCallingUid());
1213     }
1214 
1215     /**
1216      * Method called by manager, after creating a file from within application context, to send a
1217      * file descriptor for service to write the result of the profiling session to.
1218      *
1219      * Note: only expected to be called in response to a generateFile request sent to manager.
1220      */
receiveFileDescriptor(ParcelFileDescriptor fileDescriptor, long keyMostSigBits, long keyLeastSigBits)1221     public void receiveFileDescriptor(ParcelFileDescriptor fileDescriptor, long keyMostSigBits,
1222             long keyLeastSigBits) {
1223         List<TracingSession> sessions = mQueuedTracingResults.get(Binder.getCallingUid());
1224         if (sessions == null) {
1225             // No sessions for this uid, so no profiling result to write to this file descriptor.
1226             // Attempt to cleanup.
1227             finishReceiveFileDescriptor(null, fileDescriptor, null, null, false);
1228             return;
1229         }
1230 
1231         TracingSession session = null;
1232         // Iterate through and try to find the session this file is associated with using the
1233         // key values. Key values were provided from the session to the generate file call that
1234         // triggered this.
1235         String key = (new UUID(keyMostSigBits, keyLeastSigBits)).toString();
1236         for (int i = 0; i < sessions.size(); i++) {
1237             TracingSession tempSession = sessions.get(i);
1238             if (tempSession.getKey().equals(key)) {
1239                 session = tempSession;
1240                 break;
1241             }
1242         }
1243         if (session == null) {
1244             // No session for the provided key, nothing to do with this file descriptor. Attempt
1245             // to cleanup.
1246             finishReceiveFileDescriptor(session, fileDescriptor, null, null, false);
1247             return;
1248         }
1249 
1250         // At this point we've identified the session that has sent us this file descriptor.
1251         // Now, we'll create a temporary file pointing to the profiling output for that session.
1252         // If that file looks good, we'll copy it to the app's local file descriptor.
1253         File tempResultFile = new File(TEMP_TRACE_PATH
1254                 + (session.getProfilingType() == ProfilingManager.PROFILING_TYPE_SYSTEM_TRACE
1255                 ? session.getRedactedFileName() : session.getFileName()));
1256         FileInputStream tempPerfettoFileInStream = null;
1257         FileOutputStream appFileOutStream = null;
1258 
1259         try {
1260             if (!tempResultFile.exists() || tempResultFile.length() == 0L) {
1261                 // The profiling process output file does not exist or is empty, nothing to copy.
1262                 if (DEBUG) {
1263                     Log.d(TAG, "Temporary profiling output file is missing or empty, nothing to"
1264                             + " copy.");
1265                 }
1266                 finishReceiveFileDescriptor(session, fileDescriptor, tempPerfettoFileInStream,
1267                         appFileOutStream, false);
1268                 return;
1269             }
1270         } catch (SecurityException e) {
1271             // If we hit a security exception checking file exists or size then we won't be able to
1272             // copy it, attempt to cleanup and return.
1273             if (DEBUG) {
1274                 Log.d(TAG, "Exception checking if temporary file exists and is non-empty", e);
1275             }
1276             finishReceiveFileDescriptor(session, fileDescriptor, tempPerfettoFileInStream,
1277                     appFileOutStream, false);
1278             return;
1279         }
1280 
1281         // Setup file streams.
1282         try {
1283             tempPerfettoFileInStream = new FileInputStream(tempResultFile);
1284         } catch (IOException e) {
1285             // IO Exception opening temp perfetto file. No result.
1286             if (DEBUG) Log.d(TAG, "Exception opening temp perfetto file.", e);
1287             finishReceiveFileDescriptor(session, fileDescriptor, tempPerfettoFileInStream,
1288                     appFileOutStream, false);
1289             return;
1290         }
1291 
1292         // Obtain a file descriptor for the result file in app storage from
1293         // {@link ProfilingManager}
1294         if (fileDescriptor != null) {
1295             appFileOutStream = new FileOutputStream(fileDescriptor.getFileDescriptor());
1296         }
1297 
1298         if (appFileOutStream == null) {
1299             finishReceiveFileDescriptor(session, fileDescriptor, tempPerfettoFileInStream,
1300                     appFileOutStream, false);
1301             return;
1302         }
1303 
1304         // Now copy the file over.
1305         try {
1306             FileUtils.copy(tempPerfettoFileInStream, appFileOutStream);
1307         } catch (IOException e) {
1308             // Exception writing to local app file. Attempt to delete the bad copy.
1309             deleteBadCopiedFile(session);
1310             if (DEBUG) Log.d(TAG, "Exception writing to local app file.", e);
1311             finishReceiveFileDescriptor(session, fileDescriptor, tempPerfettoFileInStream,
1312                     appFileOutStream, false);
1313             return;
1314         }
1315 
1316         finishReceiveFileDescriptor(session, fileDescriptor, tempPerfettoFileInStream,
1317                 appFileOutStream, true);
1318     }
1319 
finishReceiveFileDescriptor(TracingSession session, ParcelFileDescriptor fileDescriptor, FileInputStream tempPerfettoFileInStream, FileOutputStream appFileOutStream, boolean succeeded)1320     private void finishReceiveFileDescriptor(TracingSession session,
1321             ParcelFileDescriptor fileDescriptor, FileInputStream tempPerfettoFileInStream,
1322             FileOutputStream appFileOutStream, boolean succeeded) {
1323         // Cleanup.
1324         if (tempPerfettoFileInStream != null) {
1325             try {
1326                 tempPerfettoFileInStream.close();
1327             } catch (IOException e) {
1328                 if (DEBUG) Log.d(TAG, "Failed to close temp perfetto input stream.", e);
1329             }
1330         }
1331         if (fileDescriptor != null) {
1332             try {
1333                 fileDescriptor.close();
1334             } catch (IOException e) {
1335                 if (DEBUG) Log.d(TAG, "Failed to close app file output file FileDescriptor.", e);
1336             }
1337         }
1338         if (appFileOutStream != null) {
1339             try {
1340                 appFileOutStream.close();
1341             } catch (IOException e) {
1342                 if (DEBUG) Log.d(TAG, "Failed to close app file output file stream.", e);
1343             }
1344         }
1345 
1346         if (session != null) {
1347             if (succeeded) {
1348                 advanceTracingSession(session, TracingState.COPIED_FILE);
1349             } else {
1350                 // Couldn't move file. File is still in temp directory and will be tried later.
1351                 // Leave state unchanged so it can get triggered again from the queue, but update
1352                 // the error and trigger a callback.
1353                 if (DEBUG) Log.d(TAG, "Couldn't move file to app storage.");
1354                 session.setError(ProfilingResult.ERROR_FAILED_POST_PROCESSING,
1355                         "Failed to copy result to app storage. May try again later.");
1356                 processTracingSessionResultCallback(session, false /* Do not continue */);
1357             }
1358 
1359             // Clean up temporary directory if it has been long enough to warrant it.
1360             maybeCleanupTemporaryDirectory();
1361         }
1362     }
1363 
1364     /**
1365      * An app can register multiple callbacks between this service and {@link ProfilingManager}, one
1366      * per context that the app created a manager instance with. As we do not know on this service
1367      * side which callbacks need to be triggered with this result, trigger all of them and let them
1368      * decide whether to finish delivering it.
1369      *
1370      * Call this method if a {@link TracingSession} already exists. If no session exists yet, call
1371      * {@link #processResultCallback} directly instead.
1372      *
1373      * @param session           The session for which to callback and potentially advance.
1374      * @param continueAdvancing Whether to continue advancing or stop after attempting the callback.
1375      */
1376     @VisibleForTesting
processTracingSessionResultCallback(TracingSession session, boolean continueAdvancing)1377     public void processTracingSessionResultCallback(TracingSession session,
1378             boolean continueAdvancing) {
1379         boolean succeeded = processResultCallback(session.getUid(), session.getKeyMostSigBits(),
1380                 session.getKeyLeastSigBits(), session.getErrorStatus(),
1381                 session.getDestinationFileName(OUTPUT_FILE_RELATIVE_PATH),
1382                 session.getTag(), session.getErrorMessage(), session.getTriggerType());
1383 
1384         if (continueAdvancing && succeeded) {
1385             advanceTracingSession(session, TracingState.NOTIFIED_REQUESTER);
1386         }
1387     }
1388 
1389     /**
1390      * An app can register multiple callbacks between this service and {@link ProfilingManager}, one
1391      * per context that the app created a manager instance with. As we do not know on this service
1392      * side which callbacks need to be triggered with this result, trigger all of them and let them
1393      * decide whether to finish delivering it.
1394      *
1395      * Call this directly only if no {@link TracingSession} exists yet. If a session already exists,
1396      * call {@link #processTracingSessionResultCallback} instead.
1397      *
1398      * @return whether at least one callback was successfully sent to the app.
1399      */
processResultCallback(int uid, long keyMostSigBits, long keyLeastSigBits, int status, @Nullable String fileResultPathAndName, @Nullable String tag, @Nullable String error, int triggerType)1400     private boolean processResultCallback(int uid, long keyMostSigBits, long keyLeastSigBits,
1401             int status, @Nullable String fileResultPathAndName, @Nullable String tag,
1402             @Nullable String error, int triggerType) {
1403         List<IProfilingResultCallback> perUidCallbacks = mResultCallbacks.get(uid);
1404         if (perUidCallbacks == null || perUidCallbacks.isEmpty()) {
1405             // No callbacks, nowhere to notify with result or failure.
1406             if (DEBUG) Log.d(TAG, "No callback to ProfilingManager, callback dropped.");
1407             return false;
1408         }
1409 
1410         boolean succeeded = false;
1411         for (int i = 0; i < perUidCallbacks.size(); i++) {
1412             try {
1413                 if (status == ProfilingResult.ERROR_NONE) {
1414                     perUidCallbacks.get(i).sendResult(
1415                             fileResultPathAndName, keyMostSigBits, keyLeastSigBits, status, tag,
1416                             error, triggerType);
1417                 } else {
1418                     perUidCallbacks.get(i).sendResult(
1419                             null, keyMostSigBits, keyLeastSigBits, status, tag, error, triggerType);
1420                 }
1421                 // One success is all we need to know that a callback was sent to the app.
1422                 // This is not perfect but sufficient given we cannot verify the success of
1423                 // individual listeners without either a blocking binder call into the app or an
1424                 // extra binder call back from the app.
1425                 succeeded = true;
1426             } catch (RemoteException e) {
1427                 // Failed to send result. Ignore.
1428                 if (DEBUG) Log.d(TAG, "Exception processing result callback", e);
1429             }
1430         }
1431 
1432         return succeeded;
1433     }
1434 
startProfiling(final TracingSession session)1435     private void startProfiling(final TracingSession session)
1436             throws RuntimeException {
1437         // Parse config and post processing delay out of request first, if we can't get these
1438         // we can't start the trace.
1439         int postProcessingInitialDelayMs;
1440         byte[] config;
1441         String suffix;
1442         String tag;
1443         try {
1444             postProcessingInitialDelayMs = session.getPostProcessingScheduleDelayMs();
1445             config = session.getConfigBytes();
1446             suffix = getFileSuffixForRequest(session.getProfilingType());
1447 
1448             // Create a version of tag that is non null, containing only valid filename chars,
1449             // and shortened to class defined max size.
1450             tag = session.getTag() == null
1451                     ? "" : removeInvalidFilenameChars(session.getTag());
1452             if (tag.length() > TAG_MAX_CHARS_FOR_FILENAME) {
1453                 tag = tag.substring(0, TAG_MAX_CHARS_FOR_FILENAME);
1454             }
1455         } catch (IllegalArgumentException e) {
1456             // Request couldn't be processed. This shouldn't happen.
1457             if (DEBUG) Log.d(TAG, "Request couldn't be processed", e);
1458             session.setError(ProfilingResult.ERROR_FAILED_INVALID_REQUEST, e.getMessage());
1459             // Don't bother adding the session to the queue as there is no real value in trying to
1460             // deliver this error callback again later in the case that the app no longer has a
1461             // registered listener.
1462             advanceTracingSession(session, TracingState.ERROR_OCCURRED);
1463             return;
1464 
1465         }
1466 
1467         String baseFileName = OUTPUT_FILE_PREFIX
1468                 + (tag.isEmpty() ? "" : OUTPUT_FILE_SECTION_SEPARATOR + tag)
1469                 + OUTPUT_FILE_SECTION_SEPARATOR + getFormattedDate();
1470 
1471         // Only trace files will go through the redaction process, set the name here for the file
1472         // that will be created later when results are processed.
1473         if (session.getProfilingType() == ProfilingManager.PROFILING_TYPE_SYSTEM_TRACE) {
1474             session.setRedactedFileName(baseFileName + OUTPUT_FILE_TRACE_SUFFIX);
1475         }
1476 
1477         session.setFileName(baseFileName + suffix);
1478 
1479         Process activeProfiling = startProfilingProcess(config,
1480                 TEMP_TRACE_PATH + session.getFileName());
1481 
1482         if (activeProfiling != null) {
1483             // Profiling is running, save the session.
1484             session.setActiveTrace(activeProfiling);
1485             session.setProfilingStartTimeMs(System.currentTimeMillis());
1486             mActiveTracingSessions.put(session.getKey(), session);
1487         } else {
1488             session.setError(ProfilingResult.ERROR_FAILED_EXECUTING, "Trace couldn't be started");
1489             // Don't bother adding the session to the queue as there is no real value in trying to
1490             // deliver this error callback again later in the case that the app no longer has a
1491             // registered listener.
1492             advanceTracingSession(session, TracingState.ERROR_OCCURRED);
1493             return;
1494         }
1495 
1496         // Create post process runnable, store it, and schedule it.
1497         session.setProcessResultRunnable(new Runnable() {
1498             @Override
1499             public void run() {
1500                 // Check if the profiling process is complete or reschedule the check.
1501                 checkProfilingCompleteRescheduleIfNeeded(session);
1502             }
1503         });
1504         getHandler().postDelayed(session.getProcessResultRunnable(), postProcessingInitialDelayMs);
1505 
1506         advanceTracingSession(session, TracingState.PROFILING_STARTED);
1507     }
1508 
1509     /**
1510      * Start a trace to be used for system triggered profiling.
1511      *
1512      * This should not be called while a system triggered trace is already running. If it is called
1513      * with a system triggered trace in progress, this request will be dropped.
1514      */
1515     @VisibleForTesting
startSystemTriggeredTrace()1516     public void startSystemTriggeredTrace() {
1517         if (!Flags.systemTriggeredProfilingNew()) {
1518             // Flag disabled.
1519             return;
1520         }
1521 
1522         if (!mAppTriggersLoaded) {
1523             // Until the triggers are loaded we can't create a proper config so just return.
1524             if (DEBUG) {
1525                 Log.d(TAG, "System triggered trace not started due to app triggers not loaded.");
1526             }
1527             return;
1528         }
1529 
1530         synchronized (mLock) {
1531             // Everything from the check if a system triggered trace is in progress to updating the
1532             // object to the new running trace should be in a single synchronized block to ensure
1533             // that another system triggered start is not attempted while one is in progress.
1534 
1535             if (mSystemTriggeredTraceProcess != null && mSystemTriggeredTraceProcess.isAlive()) {
1536                 // Only 1 system triggered trace should be running at a time. If one is already
1537                 // running then this should not be called, return.
1538                 if (DEBUG) {
1539                     Log.d(TAG, "System triggered trace not started due to a system triggered trace "
1540                             + "already in progress.");
1541                 }
1542                 return;
1543             }
1544 
1545             String[] packageNames = getActiveTriggerPackageNames();
1546             if (packageNames.length == 0) {
1547                 // No apps have registered interest in system triggered profiling, so don't bother
1548                 // to start a trace for it.
1549                 if (DEBUG) {
1550                     Log.d(TAG, "System triggered trace not started due to no apps registering "
1551                             + "interest");
1552                 }
1553                 return;
1554             }
1555 
1556             String uniqueSessionName = SYSTEM_TRIGGERED_SESSION_NAME_PREFIX
1557                     + System.currentTimeMillis();
1558 
1559             byte[] config = Configs.generateSystemTriggeredTraceConfig(uniqueSessionName,
1560                     packageNames,
1561                     mTestPackageName != null);
1562             String outputFile = TEMP_TRACE_PATH + SYSTEM_TRIGGERED_SESSION_NAME_PREFIX
1563                     + OUTPUT_FILE_IN_PROGRESS + OUTPUT_FILE_UNREDACTED_TRACE_SUFFIX;
1564 
1565             Process activeTrace = startProfilingProcess(config, outputFile);
1566 
1567             if (activeTrace != null) {
1568                 mSystemTriggeredTraceProcess = activeTrace;
1569                 mSystemTriggeredTraceUniqueSessionName = uniqueSessionName;
1570                 mLastStartedSystemTriggeredTraceMs = System.currentTimeMillis();
1571             }
1572         }
1573     }
1574 
1575     /**
1576      * Start the actual profiling process with necessary config details.
1577      *
1578      * @return the started process if it started successfully, or null if it failed to start.
1579      */
1580     @Nullable
startProfilingProcess(byte[] config, String outputFile)1581     private Process startProfilingProcess(byte[] config, String outputFile) {
1582         try {
1583             ProcessBuilder processBuilder = new ProcessBuilder("/system/bin/perfetto", "-o",
1584                     outputFile, "-c", "-");
1585             Process activeProfiling = processBuilder.start();
1586             activeProfiling.getOutputStream().write(config);
1587             activeProfiling.getOutputStream().close();
1588             return activeProfiling;
1589         } catch (Exception e) {
1590             // Catch all exceptions related to starting process as they'll all be handled similarly.
1591             if (DEBUG) Log.e(TAG, "Profiling couldn't be started", e);
1592             return null;
1593         }
1594     }
1595 
1596     /**
1597      * Process a trigger for a uid + package name + trigger combination. This is done by verifying
1598      * that a trace is active, the app has registered interest in this combo, and that both system
1599      * and app provided rate limiting allow for it. If confirmed, it will proceed to clone the
1600      * active profiling and continue processing the result.
1601      *
1602      * Cloning will fork the running trace, stop the new forked trace, and output the result to a
1603      * separate file. This leaves the original trace running.
1604      */
processTrigger(int uid, @NonNull String packageName, int triggerType)1605     public void processTrigger(int uid, @NonNull String packageName, int triggerType) {
1606         if (!Flags.systemTriggeredProfilingNew()) {
1607             // Flag disabled.
1608             return;
1609         }
1610 
1611         // Don't block the calling thread.
1612         getHandler().post(new Runnable() {
1613             @Override
1614             public void run() {
1615                 processTriggerInternal(uid, packageName, triggerType);
1616             }
1617         });
1618     }
1619 
1620     /**
1621      * Internal call to process trigger, not to be called on the thread that passed the trigger in.
1622      */
1623     @VisibleForTesting
processTriggerInternal(int uid, @NonNull String packageName, int triggerType)1624     public void processTriggerInternal(int uid, @NonNull String packageName, int triggerType) {
1625         synchronized (mLock) {
1626             if (mSystemTriggeredTraceUniqueSessionName == null) {
1627                 // If we don't have the session name then we don't know how to clone the trace so
1628                 // stop it if it's still running and then return.
1629                 stopSystemTriggeredTraceLocked();
1630 
1631                 // There is no active system triggered trace so there's nothing to clone. Return.
1632                 if (DEBUG) {
1633                     Log.d(TAG, "Requested clone system triggered trace but we don't have the "
1634                             + "session name.");
1635                 }
1636                 return;
1637             }
1638 
1639             if (mSystemTriggeredTraceProcess == null || !mSystemTriggeredTraceProcess.isAlive()) {
1640                 // If we make it to this path then session name wasn't set to null but can't be used
1641                 // anymore as its associated trace is not running, so set to null now.
1642                 mSystemTriggeredTraceUniqueSessionName = null;
1643 
1644                 // There is no active system triggered trace so there's nothing to clone. Return.
1645                 if (DEBUG) {
1646                     Log.d(TAG, "Requested clone system triggered trace but no trace active.");
1647                 }
1648                 return;
1649             }
1650         }
1651 
1652         // Then check if the app has registered interest in this combo.
1653         SparseArray<ProfilingTriggerData> perProcessTriggers = mAppTriggers.get(packageName, uid);
1654         if (perProcessTriggers == null) {
1655             // This uid hasn't registered any triggers.
1656             if (DEBUG) {
1657                 Log.d(TAG, String.format("Profiling triggered for uid %d with no registered "
1658                         + "triggers", uid));
1659             }
1660             return;
1661         }
1662 
1663         ProfilingTriggerData trigger = perProcessTriggers.get(triggerType);
1664         if (trigger == null) {
1665             // This uid hasn't registered a trigger for this type.
1666             if (DEBUG) {
1667                 Log.d(TAG, String.format("Profiling triggered for uid %d and trigger %d, but "
1668                         + "app has not registered for this trigger type.", uid, triggerType));
1669             }
1670             return;
1671         }
1672 
1673         // Now apply system and app provided rate limiting.
1674         if (System.currentTimeMillis() - trigger.getLastTriggeredTimeMs()
1675                 < trigger.getRateLimitingPeriodHours() * 60L * 60L * 1000L) {
1676             // App provided rate limiting doesn't allow for this run, return.
1677             if (DEBUG) {
1678                 Log.d(TAG, String.format("Profiling triggered for uid %d and trigger %d but blocked"
1679                         + " by app provided rate limiting ", uid, triggerType));
1680             }
1681             return;
1682         }
1683 
1684         // If this is from the test package, skip system rate limiting.
1685         if (!packageName.equals(mTestPackageName)) {
1686             int systemRateLimiterResult = getRateLimiter().isProfilingRequestAllowed(uid,
1687                     ProfilingManager.PROFILING_TYPE_SYSTEM_TRACE, true, null);
1688             if (systemRateLimiterResult != RateLimiter.RATE_LIMIT_RESULT_ALLOWED) {
1689                 // Blocked by system rate limiter, return. Since this is system triggered there is
1690                 // no callback and therefore no need to distinguish between per app and system
1691                 // denials within the system rate limiter.
1692                 if (DEBUG) {
1693                     Log.d(TAG, String.format("Profiling triggered for uid %d and trigger %d but "
1694                             + "blocked by system rate limiting ", uid, triggerType));
1695                 }
1696                 return;
1697             }
1698         }
1699 
1700         // Now that it's approved by both rate limiters, update their values.
1701         trigger.setLastTriggeredTimeMs(System.currentTimeMillis());
1702 
1703         // If we made it this far, a trace is running, the app has registered interest in this
1704         // trigger, and rate limiting allows for capturing the result.
1705 
1706         // Create the file names
1707         String baseFileName = OUTPUT_FILE_PREFIX
1708                 + OUTPUT_FILE_SECTION_SEPARATOR + OUTPUT_FILE_TRIGGER
1709                 + OUTPUT_FILE_SECTION_SEPARATOR + triggerType
1710                 + OUTPUT_FILE_SECTION_SEPARATOR + getFormattedDate();
1711         String unredactedFullName = baseFileName + OUTPUT_FILE_UNREDACTED_TRACE_SUFFIX;
1712 
1713         try {
1714             // Try to clone the running trace.
1715             Process clone = Runtime.getRuntime().exec(new String[] {
1716                     "/system/bin/perfetto",
1717                     "--clone-by-name",
1718                     mSystemTriggeredTraceUniqueSessionName,
1719                     "--out",
1720                     TEMP_TRACE_PATH + unredactedFullName});
1721 
1722             // Wait for cloned process to stop.
1723             if (!clone.waitFor(mPerfettoDestroyTimeoutMs, TimeUnit.MILLISECONDS)) {
1724                 // Cloned process did not stop, try to stop it forcibly.
1725                 if (DEBUG) {
1726                     Log.d(TAG, "Cloned system triggered trace didn't stop on its own, trying to "
1727                             + "stop it forcibly.");
1728                 }
1729                 clone.destroyForcibly();
1730 
1731                 // Wait again to see if it stops now.
1732                 if (!clone.waitFor(mPerfettoDestroyTimeoutMs, TimeUnit.MILLISECONDS)) {
1733                     // Nothing more to do, result won't be ready so return.
1734                     if (DEBUG) Log.d(TAG, "Cloned system triggered trace timed out.");
1735                     return;
1736                 }
1737             }
1738         } catch (IOException | InterruptedException e) {
1739             // Failed. There's nothing to clean up as we haven't created a session for this clone
1740             // yet so just fail quietly. The result for this trigger instance combo will be lost.
1741             if (DEBUG) Log.d(TAG, "Failed to clone running system triggered trace.", e);
1742             return;
1743         }
1744 
1745         // If we get here the clone was successful. Create a new TracingSession to track this and
1746         // continue moving it along the processing process.
1747         TracingSession session = new TracingSession(
1748                 ProfilingManager.PROFILING_TYPE_SYSTEM_TRACE, uid, packageName, triggerType);
1749         session.setRedactedFileName(baseFileName + OUTPUT_FILE_TRACE_SUFFIX);
1750         session.setFileName(unredactedFullName);
1751         session.setProfilingStartTimeMs(System.currentTimeMillis());
1752         moveSessionToQueue(session, true);
1753         advanceTracingSession(session, TracingState.PROFILING_FINISHED);
1754 
1755         maybePersistToDisk();
1756     }
1757 
1758     /** Add a profiling trigger to the supporting data structure. */
1759     @VisibleForTesting
addTrigger(int uid, @NonNull String packageName, int triggerType, int rateLimitingPeriodHours)1760     public void addTrigger(int uid, @NonNull String packageName, int triggerType,
1761             int rateLimitingPeriodHours) {
1762         addTrigger(new ProfilingTriggerData(uid, packageName, triggerType, rateLimitingPeriodHours),
1763                 true);
1764     }
1765 
1766     /**
1767      * Add a profiling trigger to the supporting data structure.
1768      *
1769      * @param trigger       The trigger to add.
1770      * @param maybePersist  Whether to persist to disk, if eligible based on frequency. This is
1771      *                          intended to be set to false only when loading triggers from disk.
1772      */
1773     @VisibleForTesting
addTrigger(ProfilingTriggerData trigger, boolean maybePersist)1774     public void addTrigger(ProfilingTriggerData trigger, boolean maybePersist) {
1775         if (!Flags.systemTriggeredProfilingNew()) {
1776             // Flag disabled.
1777             return;
1778         }
1779 
1780         SparseArray<ProfilingTriggerData> perProcessTriggers = mAppTriggers.get(
1781                 trigger.getPackageName(), trigger.getUid());
1782 
1783         if (perProcessTriggers == null) {
1784             perProcessTriggers = new SparseArray<ProfilingTriggerData>();
1785             mAppTriggers.put(trigger.getPackageName(), trigger.getUid(), perProcessTriggers);
1786         }
1787 
1788         // Only 1 trigger is allowed per uid + trigger type so this will override any previous
1789         // triggers of this type registered for this uid.
1790         perProcessTriggers.put(trigger.getTriggerType(), trigger);
1791 
1792         if (maybePersist) {
1793             maybePersistToDisk();
1794         }
1795     }
1796 
1797     /** Get a list of all package names which have registered profiling triggers. */
getActiveTriggerPackageNames()1798     private String[] getActiveTriggerPackageNames() {
1799         // Since only system trace is supported for triggers, we can simply grab the key set of the
1800         // backing map for the ProcessMap which will contain all the package names. Once other
1801         // profiling types are supported, we'll need to filter these more intentionally to just the
1802         // ones that have an associated trace trigger.
1803         Set<String> packageNamesSet = mAppTriggers.getMap().keySet();
1804         return packageNamesSet.toArray(new String[packageNamesSet.size()]);
1805     }
1806 
1807     /**
1808         This method will check if the profiling subprocess is still alive. If it's still alive and
1809         there is still time permitted to run, another check will be scheduled. If the process is
1810         still alive but max allotted processing time has been exceeded, the profiling process will
1811         be stopped and results processed and returned to client. If the profiling process is
1812         complete results will be processed and returned to the client.
1813      */
checkProfilingCompleteRescheduleIfNeeded(TracingSession session)1814     private void checkProfilingCompleteRescheduleIfNeeded(TracingSession session) {
1815         long processingTimeRemaining = session.getMaxProfilingTimeAllowedMs()
1816                 - (System.currentTimeMillis() - session.getProfilingStartTimeMs());
1817 
1818         if (session.getActiveTrace().isAlive()
1819                 && processingTimeRemaining >= 0) {
1820             // still running and under max allotted processing time, reschedule the check.
1821             getHandler().postDelayed(session.getProcessResultRunnable(),
1822                     Math.min(mProfilingRecheckDelayMs, processingTimeRemaining));
1823         } else if (session.getActiveTrace().isAlive()
1824                 && processingTimeRemaining < 0) {
1825             // still running but exceeded max allotted processing time, stop profiling and deliver
1826             // what results are available.
1827             stopProfiling(session.getKey());
1828         } else {
1829             // complete, process results and deliver.
1830             session.setProcessResultRunnable(null);
1831             moveSessionToQueue(session, true);
1832             advanceTracingSession(session, TracingState.PROFILING_FINISHED);
1833         }
1834     }
1835 
1836     /** Stop any active profiling sessions belonging to the provided uid. */
stopAllProfilingForUid(int uid)1837     private void stopAllProfilingForUid(int uid) {
1838         if (mActiveTracingSessions.isEmpty()) {
1839             // If there are no active traces, then there are none for this uid.
1840             return;
1841         }
1842 
1843         // Iterate through active sessions and stop profiling if they belong to the provided uid.
1844         // Note: Currently, this will only ever have 1 session.
1845         for (int i = 0; i < mActiveTracingSessions.size(); i++) {
1846             TracingSession session = mActiveTracingSessions.valueAt(i);
1847             if (session.getUid() == uid) {
1848                 stopProfiling(session);
1849             }
1850         }
1851     }
1852 
1853     /** Stop active profiling for the given session key. */
stopProfiling(String key)1854     private void stopProfiling(String key) {
1855         TracingSession session = mActiveTracingSessions.get(key);
1856         stopProfiling(session);
1857     }
1858 
1859     /** Stop active profiling for the given session. */
stopProfiling(TracingSession session)1860     private void stopProfiling(TracingSession session) {
1861         if (session == null || session.getActiveTrace() == null) {
1862             if (DEBUG) Log.d(TAG, "No active trace, nothing to stop.");
1863             return;
1864         }
1865 
1866         if (session.getProcessResultRunnable() == null) {
1867             if (DEBUG) {
1868                 Log.d(TAG,
1869                         "No runnable, it either stopped already or is in the process of stopping.");
1870             }
1871             return;
1872         }
1873 
1874         // Remove the post processing runnable set with the default timeout. After stopping use the
1875         // same runnable to process immediately.
1876         getHandler().removeCallbacks(session.getProcessResultRunnable());
1877 
1878         // End the tracing session.
1879         session.getActiveTrace().destroyForcibly();
1880         try {
1881             if (!session.getActiveTrace().waitFor(mPerfettoDestroyTimeoutMs,
1882                     TimeUnit.MILLISECONDS)) {
1883                 if (DEBUG) Log.d(TAG, "Stopping of running trace process timed out.");
1884                 return;
1885             }
1886         } catch (InterruptedException e) {
1887             if (DEBUG) Log.d(TAG, "Stopping of running trace error occurred.", e);
1888             return;
1889         }
1890 
1891         // If we made it here the result is ready, now run the post processing runnable.
1892         getHandler().post(session.getProcessResultRunnable());
1893     }
1894 
1895     /** Check whether a profiling session is running. Not specific to any process. */
areAnyTracesRunning()1896     public boolean areAnyTracesRunning() throws RuntimeException {
1897         for (int i = 0; i < mActiveTracingSessions.size(); i++) {
1898             if (isTraceRunning(mActiveTracingSessions.keyAt(i))) {
1899                 return true;
1900             }
1901         }
1902         return false;
1903     }
1904 
1905     /**
1906      * Cleanup the data structure of active sessions. Non active sessions are never expected to be
1907      * present in {@link mActiveTracingSessions} as they would be moved to
1908      * {@link mQueuedTracingResults} when profiling completes. If a session is present but not
1909      * running, remove it. If a session has a not alive process, try to stop it.
1910      */
cleanupActiveTracingSessions()1911     public void cleanupActiveTracingSessions() throws RuntimeException {
1912         // Create a temporary list to store the keys of sessions to be stopped.
1913         ArrayList<String> sessionsToStop = new ArrayList<String>();
1914 
1915         // Iterate through in reverse order so we can immediately remove the non running sessions
1916         // that don't have to be stopped.
1917         for (int i = mActiveTracingSessions.size() - 1; i >= 0; i--) {
1918             String key = mActiveTracingSessions.keyAt(i);
1919             TracingSession session = mActiveTracingSessions.get(key);
1920 
1921             if (session == null || session.getActiveTrace() == null) {
1922                 // Profiling isn't running, remove from list.
1923                 mActiveTracingSessions.removeAt(i);
1924             } else if (!session.getActiveTrace().isAlive()) {
1925                 // Profiling process exists but isn't alive, add to list of sessions to stop. Do not
1926                 // stop here due to potential unanticipated modification of list being iterated
1927                 // through.
1928                 sessionsToStop.add(key);
1929             }
1930         }
1931 
1932         // If we have any sessions to stop, now is the time.
1933         if (!sessionsToStop.isEmpty()) {
1934             for (int i = 0; i < sessionsToStop.size(); i++) {
1935                 stopProfiling(sessionsToStop.get(i));
1936             }
1937         }
1938     }
1939 
1940     /** Check whether a profiling session with the provided key is currently running. */
isTraceRunning(String key)1941     public boolean isTraceRunning(String key) throws RuntimeException {
1942         TracingSession session = mActiveTracingSessions.get(key);
1943         if (session == null || session.getActiveTrace() == null) {
1944             // No subprocess, nothing running.
1945             if (DEBUG) Log.d(TAG, "No subprocess, nothing running.");
1946             return false;
1947         } else if (session.getActiveTrace().isAlive()) {
1948             // Subprocess exists and is alive.
1949             if (DEBUG) Log.d(TAG, "Subprocess exists and is alive, trace is running.");
1950             return true;
1951         } else {
1952             // Subprocess exists but is not alive, nothing running.
1953             if (DEBUG) Log.d(TAG, "Subprocess exists but is not alive, nothing running.");
1954             return false;
1955         }
1956     }
1957 
1958     /**
1959      * Begin moving result to storage by validating and then sending a request to
1960      * {@link ProfilingManager} for a file to write to. File will be returned as a
1961      * {@link ParcelFileDescriptor} via {@link sendFileDescriptor}.
1962      */
1963     @VisibleForTesting
beginMoveFileToAppStorage(TracingSession session)1964     public void beginMoveFileToAppStorage(TracingSession session) {
1965         if (session.getState().getValue() >= TracingState.ERROR_OCCURRED.getValue()) {
1966             // This should not have happened, if the session has a state of error or later then why
1967             // are we trying to continue processing it? Remove from all data stores just in case.
1968             if (DEBUG) {
1969                 Log.d(TAG, "Attempted beginMoveFileToAppStorage on a session with status error"
1970                         + " or an invalid status.");
1971             }
1972             mActiveTracingSessions.remove(session.getKey());
1973             cleanupTracingSession(session);
1974             return;
1975         }
1976 
1977         List<IProfilingResultCallback> perUidCallbacks = mResultCallbacks.get(session.getUid());
1978         if (perUidCallbacks == null || perUidCallbacks.isEmpty()) {
1979             // No callback so no way to obtain a file to populate with result.
1980             if (DEBUG) Log.d(TAG, "No callback to ProfilingManager, callback dropped.");
1981             // TODO: b/333456916 run a cleanup of old results based on a max size and time.
1982             return;
1983         }
1984 
1985         requestFileForResult(perUidCallbacks, session);
1986     }
1987 
1988     /**
1989      * Delete a file which failed to copy via ProfilingManager.
1990      */
deleteBadCopiedFile(TracingSession session)1991     private void deleteBadCopiedFile(TracingSession session) {
1992         List<IProfilingResultCallback> perUidCallbacks = mResultCallbacks.get(session.getUid());
1993         for (int i = 0; i < perUidCallbacks.size(); i++) {
1994             try {
1995                 String fileName =
1996                         session.getProfilingType() == ProfilingManager.PROFILING_TYPE_SYSTEM_TRACE
1997                         ? session.getRedactedFileName() : session.getFileName();
1998                 IProfilingResultCallback callback = perUidCallbacks.get(i);
1999                 if (callback.asBinder().isBinderAlive()) {
2000                     callback.deleteFile(OUTPUT_FILE_RELATIVE_PATH + fileName);
2001                     // Only need one delete call, return.
2002                     return;
2003                 }
2004             } catch (RemoteException e) {
2005                 // Binder exception deleting file. Continue trying other callbacks for this process.
2006                 if (DEBUG) Log.d(TAG, "Binder exception deleting file. Trying next callback", e);
2007             }
2008         }
2009     }
2010 
2011     /**
2012      * Request a {@link ParcelFileDescriptor} to a new file in app storage from the first live
2013      * callback for this uid.
2014      *
2015      * The new file is created by {@link ProfilingManager} from within app context. We only need a
2016      * single file, which can be created from any of the contexts belonging to the app that
2017      * requested this profiling, so it does not matter which of the requesting app's callbacks we
2018      * use.
2019      */
2020     @Nullable
requestFileForResult( @onNull List<IProfilingResultCallback> perUidCallbacks, TracingSession session)2021     private void requestFileForResult(
2022             @NonNull List<IProfilingResultCallback> perUidCallbacks, TracingSession session) {
2023         String fileName = session.getProfilingType() == ProfilingManager.PROFILING_TYPE_SYSTEM_TRACE
2024                 ? session.getRedactedFileName()
2025                 : session.getFileName();
2026         for (int i = 0; i < perUidCallbacks.size(); i++) {
2027             try {
2028                 IProfilingResultCallback callback = perUidCallbacks.get(i);
2029                 if (callback.asBinder().isBinderAlive()) {
2030                     // Great, this one works! Call it and exit if we don't hit an exception.
2031                     perUidCallbacks.get(i).generateFile(OUTPUT_FILE_RELATIVE_PATH, fileName,
2032                             session.getKeyMostSigBits(), session.getKeyLeastSigBits());
2033                     return;
2034                 }
2035             } catch (RemoteException e) {
2036                 // Binder exception getting file. Continue trying other callbacks for this process.
2037                 if (DEBUG) Log.d(TAG, "Binder exception getting file. Trying next callback", e);
2038             }
2039         }
2040         if (DEBUG) Log.d(TAG, "Failed to obtain file descriptor from callbacks.");
2041     }
2042 
2043     /** Handle a result which required redaction by attempting to kick off redaction process. */
2044     @VisibleForTesting
handleRedactionRequiredResult(TracingSession session)2045     public void handleRedactionRequiredResult(TracingSession session) {
2046         try {
2047             // We need to create an empty file for the redaction process to write the output into.
2048             File emptyRedactedTraceFile = new File(TEMP_TRACE_PATH
2049                     + session.getRedactedFileName());
2050             emptyRedactedTraceFile.createNewFile();
2051         } catch (Exception exception) {
2052             if (DEBUG) Log.e(TAG, "Creating empty redacted file failed.", exception);
2053             session.setError(ProfilingResult.ERROR_FAILED_POST_PROCESSING);
2054             advanceTracingSession(session, TracingState.ERROR_OCCURRED);
2055             return;
2056         }
2057 
2058         try {
2059             // Start the redaction process and log the time of start.  Redaction has
2060             // mRedactionMaxRuntimeAllottedMs to complete. Redaction status will be checked every
2061             // mRedactionCheckFrequencyMs.
2062             ProcessBuilder redactionProcess = new ProcessBuilder(
2063                     "/apex/com.android.profiling/bin/trace_redactor",
2064                     TEMP_TRACE_PATH + session.getFileName(),
2065                     TEMP_TRACE_PATH + session.getRedactedFileName(),
2066                     session.getPackageName());
2067             session.setActiveRedaction(redactionProcess.start());
2068             session.setRedactionStartTimeMs(System.currentTimeMillis());
2069         } catch (Exception exception) {
2070             if (DEBUG) Log.e(TAG, "Redaction failed to run completely.", exception);
2071             session.setError(ProfilingResult.ERROR_FAILED_POST_PROCESSING);
2072             advanceTracingSession(session, TracingState.ERROR_OCCURRED);
2073             return;
2074         }
2075 
2076         session.setProcessResultRunnable(new Runnable() {
2077 
2078             @Override
2079             public void run() {
2080                 checkRedactionStatus(session);
2081             }
2082         });
2083         getHandler().postDelayed(session.getProcessResultRunnable(),
2084                 mRedactionCheckFrequencyMs);
2085     }
2086 
checkRedactionStatus(TracingSession session)2087     private void checkRedactionStatus(TracingSession session) {
2088         // Check if redaction is complete.
2089         if (!session.getActiveRedaction().isAlive()) {
2090             handleRedactionComplete(session);
2091             session.setProcessResultRunnable(null);
2092             return;
2093         }
2094 
2095         // Check if we are over the mRedactionMaxRuntimeAllottedMs threshold.
2096         if ((System.currentTimeMillis() - session.getRedactionStartTimeMs())
2097                 > mRedactionMaxRuntimeAllottedMs) {
2098             if (DEBUG) Log.d(TAG, "Redaction process has timed out");
2099 
2100             session.getActiveRedaction().destroyForcibly();
2101             session.setProcessResultRunnable(null);
2102             session.setError(ProfilingResult.ERROR_FAILED_POST_PROCESSING);
2103             advanceTracingSession(session, TracingState.ERROR_OCCURRED);
2104             return;
2105         }
2106 
2107         // Schedule the next check.
2108         getHandler().postDelayed(session.getProcessResultRunnable(),
2109                 Math.min(mRedactionCheckFrequencyMs, mRedactionMaxRuntimeAllottedMs
2110                         - (System.currentTimeMillis() - session.getRedactionStartTimeMs())));
2111 
2112     }
2113 
handleRedactionComplete(TracingSession session)2114     private void handleRedactionComplete(TracingSession session) {
2115         int redactionErrorCode = session.getActiveRedaction().exitValue();
2116         if (redactionErrorCode != 0) {
2117             // Redaction process failed. This failure cannot be recovered.
2118             if (DEBUG) {
2119                 Log.d(TAG, String.format("Redaction processed failed with error code: %s",
2120                         redactionErrorCode));
2121             }
2122             session.setError(ProfilingResult.ERROR_FAILED_POST_PROCESSING);
2123             advanceTracingSession(session, TracingState.ERROR_OCCURRED);
2124             return;
2125         }
2126 
2127         // At this point redaction has completed successfully it is safe to delete the
2128         // unredacted trace file unless {@link mKeepResultInTempDir} has been enabled.
2129         synchronized (mLock) {
2130             if (!mKeepResultInTempDir) {
2131                 deleteProfilingFiles(session,
2132                         false, /* Don't delete the newly redacted file */
2133                         true); /* Do delete the no longer needed unredacted file.*/
2134             }
2135         }
2136 
2137         advanceTracingSession(session, TracingState.REDACTED);
2138     }
2139 
2140     /**
2141      * Handle retained temporary files due to {@link mKeepResultInTempDir} being enabled, by
2142      * attempting to make them publicly readable and logging their location
2143      */
handleRetainedTempFiles(TracingSession session)2144     private void handleRetainedTempFiles(TracingSession session) {
2145         synchronized (mLock) {
2146             if (!mKeepResultInTempDir) {
2147                 // Results are only retained if {@link mKeepResultInTempDir} is enabled, so don't
2148                 // log the locations if it's disabled.
2149                 return;
2150             }
2151 
2152             // For all types, output the location of the original profiling output file. For trace,
2153             // this will be the unredacted copy. For all other types, this will be the only output
2154             // file.
2155             boolean makeReadableSucceeded = makeFileReadable(session.getFileName());
2156             logRetainedFileDetails(session.getFileName(), makeReadableSucceeded);
2157 
2158             if (session.getProfilingType() == ProfilingManager.PROFILING_TYPE_SYSTEM_TRACE) {
2159                 // For a trace, output the location of the redacted file.
2160                 makeReadableSucceeded = makeFileReadable(session.getRedactedFileName());
2161                 logRetainedFileDetails(session.getFileName(), makeReadableSucceeded);
2162             }
2163         }
2164     }
2165 
2166     /** Wrapper to log all necessary information about retained file locations. */
logRetainedFileDetails(String fileName, boolean readable)2167     private void logRetainedFileDetails(String fileName, boolean readable) {
2168         if (readable) {
2169             Log.i(TAG, "Profiling file retained at: " + TEMP_TRACE_PATH + fileName);
2170         } else {
2171             Log.i(TAG, "Profiling file retained at: " + TEMP_TRACE_PATH + fileName
2172                     + " | File is not publicly accessible, root access is required to read.");
2173         }
2174     }
2175 
2176     /**
2177      * Make the provided file within the temp trace directory publicly readable. Access is still
2178      * limited by selinux so only adbd will be additionally able to access the file due to this
2179      * change.
2180      *
2181      * @return whether making the file readable succeeded.
2182      */
2183     @SuppressWarnings("SetWorldReadable")
makeFileReadable(String fileName)2184     private boolean makeFileReadable(String fileName) {
2185         try {
2186             File file = new File(TEMP_TRACE_PATH + fileName);
2187             return file.setReadable(true, false);
2188         } catch (Exception e) {
2189             Log.w(TAG, "Failed to make file readable for testing.", e);
2190             return false;
2191         }
2192     }
2193 
2194     /**
2195      * Called whenever a new global listener has been added to the specified uid.
2196      * Attempts to process queued results if present.
2197      */
2198     @VisibleForTesting
handleQueuedResults(int uid)2199     public void handleQueuedResults(int uid) {
2200         List<TracingSession> queuedSessions = mQueuedTracingResults.get(uid);
2201         if (queuedSessions == null || queuedSessions.isEmpty()) {
2202             // No queued results for this uid, nothing to handle. Attempt to cleanup the queue for
2203             // all other uids before exiting.
2204             maybeCleanupQueue();
2205             return;
2206         }
2207 
2208         // Triggering the callbacks may result in the object being removed from the class level
2209         // queue list, ensure this remains safe by using a unmodifiable shallow copy of the list.
2210         List<TracingSession> unmodifiableQueuedSessions = List.copyOf(queuedSessions);
2211         for (int i = 0; i < unmodifiableQueuedSessions.size(); i++) {
2212             TracingSession session = unmodifiableQueuedSessions.get(i);
2213 
2214             // Check if we already retried too many times and discard the result if we have.
2215             if (session.getRetryCount() >= mMaxResultRedeliveryCount) {
2216                 cleanupTracingSession(session, queuedSessions);
2217                 continue;
2218             }
2219             session.incrementRetryCount();
2220 
2221             // Advance with new state null so that it picks up where it left off.
2222             advanceTracingSession(session, null);
2223         }
2224 
2225         // Now attempt to cleanup the queue.
2226         maybeCleanupQueue();
2227     }
2228 
2229     /** Run through all queued sessions and clean up the ones that are too old. */
maybeCleanupQueue()2230     private void maybeCleanupQueue() {
2231         List<TracingSession> sessionsToRemove = new ArrayList();
2232         // Iterate in reverse so we can remove the index if empty.
2233         for (int i = mQueuedTracingResults.size() - 1; i >= 0; i--) {
2234             List<TracingSession> sessions = mQueuedTracingResults.valueAt(i);
2235             if (sessions != null && !sessions.isEmpty()) {
2236                 sessionsToRemove.clear();
2237                 for (int j = 0; j < sessions.size(); j++) {
2238                     TracingSession session = sessions.get(j);
2239                     if (session.getProfilingStartTimeMs() + QUEUED_RESULT_MAX_RETAINED_DURATION_MS
2240                             < System.currentTimeMillis()) {
2241                         cleanupTracingSession(session);
2242                         sessionsToRemove.add(session);
2243                     }
2244                 }
2245                 sessions.removeAll(sessionsToRemove);
2246                 if (sessions.isEmpty()) {
2247                     mQueuedTracingResults.removeAt(i);
2248                 }
2249             } else {
2250                 mQueuedTracingResults.removeAt(i);
2251             }
2252         }
2253     }
2254 
2255     /**
2256      * Cleanup is intended for when we're done with a queued trace session, whether successful or
2257      * not.
2258      *
2259      * Cleanup will attempt to delete the temporary file(s) and then remove it from the queue.
2260      */
2261     @VisibleForTesting
cleanupTracingSession(TracingSession session)2262     public void cleanupTracingSession(TracingSession session) {
2263         List<TracingSession> queuedSessions = mQueuedTracingResults.get(session.getUid());
2264         cleanupTracingSession(session, queuedSessions);
2265     }
2266 
2267     /**
2268      * Cleanup is intended for when we're done with a queued trace session, whether successful or
2269      * not.
2270      *
2271      * Cleanup will attempt to delete the temporary file(s) and then remove it from the queue.
2272      */
cleanupTracingSession(TracingSession session, @Nullable List<TracingSession> queuedSessions)2273     private void cleanupTracingSession(TracingSession session,
2274             @Nullable List<TracingSession> queuedSessions) {
2275         synchronized (mLock) {
2276             if (mKeepResultInTempDir) {
2277                 // If {@link mKeepResultInTempDir} is enabled, don't cleanup anything. Continue
2278                 // progressing as if cleanup is complete.
2279                 advanceTracingSession(session, TracingState.CLEANED_UP);
2280                 return;
2281             }
2282         }
2283 
2284         // Delete all files
2285         deleteProfilingFiles(session, true, true);
2286 
2287         if (queuedSessions != null) {
2288             queuedSessions.remove(session);
2289             if (queuedSessions.isEmpty()) {
2290                 mQueuedTracingResults.remove(session.getUid());
2291             }
2292         }
2293 
2294         advanceTracingSession(session, TracingState.CLEANED_UP);
2295     }
2296 
2297     /**
2298      * Attempt to delete profiling output.
2299      *
2300      * If both boolean params are false, this method expectedly does nothing.
2301      *
2302      * @param deleteRedacted Whether to delete the redacted file.
2303      * @param deleteUnredacted Whether to delete the unredacted file.
2304      */
deleteProfilingFiles(TracingSession session, boolean deleteRedacted, boolean deleteUnredacted)2305     private void deleteProfilingFiles(TracingSession session, boolean deleteRedacted,
2306             boolean deleteUnredacted) {
2307         if (deleteRedacted) {
2308             try {
2309                 Files.deleteIfExists(Path.of(TEMP_TRACE_PATH + session.getRedactedFileName()));
2310             } catch (Exception exception) {
2311                 if (DEBUG) Log.e(TAG, "Failed to delete file.", exception);
2312             }
2313         }
2314 
2315         if (deleteUnredacted) {
2316             try {
2317                 Files.deleteIfExists(Path.of(TEMP_TRACE_PATH + session.getFileName()));
2318             } catch (Exception exception) {
2319                 if (DEBUG) Log.e(TAG, "Failed to delete file.", exception);
2320             }
2321         }
2322     }
2323 
2324     /**
2325      * Move session to list of queued sessions. Removes the session from the list of active
2326      * sessions, if it is present.
2327      *
2328      * Sessions are expected to be in the queue when their states are between PROFILING_FINISHED and
2329      * NOTIFIED_REQUESTER, inclusive.
2330      *
2331      * Sessions should only be added to the queue with a valid profiling start time. Sessions added
2332      * without a valid start time may be cleaned up in middle of their execution and fail to deliver
2333      * any result.
2334      *
2335      * @param session      the session to move to the queue
2336      * @param maybePersist whether to persist the queue to disk if the queue is eligible to be
2337      *          persisted
2338      */
moveSessionToQueue(TracingSession session, boolean maybePersist)2339     private void moveSessionToQueue(TracingSession session, boolean maybePersist) {
2340         if (DEBUG && session.getProfilingStartTimeMs() == 0) {
2341             Log.e(TAG, "Attempting to move session to queue without a start time set.",
2342                     new Throwable());
2343         }
2344 
2345         List<TracingSession> queuedResults = mQueuedTracingResults.get(session.getUid());
2346         if (queuedResults == null) {
2347             queuedResults = new ArrayList<TracingSession>();
2348             mQueuedTracingResults.put(session.getUid(), queuedResults);
2349         }
2350         queuedResults.add(session);
2351         mActiveTracingSessions.remove(session.getKey());
2352 
2353         if (maybePersist) {
2354             maybePersistToDisk();
2355         }
2356     }
2357 
needsRedaction(TracingSession session)2358     private boolean needsRedaction(TracingSession session) {
2359         return session.getProfilingType() == ProfilingManager.PROFILING_TYPE_SYSTEM_TRACE;
2360     }
2361 
getHandler()2362     private Handler getHandler() {
2363         if (mHandler == null) {
2364             mHandler = new Handler(mHandlerThread.getLooper());
2365         }
2366         return mHandler;
2367     }
2368 
getRateLimiter()2369     private RateLimiter getRateLimiter() {
2370         if (mRateLimiter == null) {
2371             mRateLimiter = new RateLimiter(new RateLimiter.HandlerCallback() {
2372                 @Override
2373                 public Handler obtainHandler() {
2374                     return getHandler();
2375                 }
2376             });
2377         }
2378         return mRateLimiter;
2379     }
2380 
getFormattedDate()2381     private String getFormattedDate() {
2382         if (mCalendar == null) {
2383             mCalendar = Calendar.getInstance(TimeZone.getTimeZone("GMT"));
2384         }
2385         if (mDateFormat == null) {
2386             mDateFormat = new SimpleDateFormat("yyyy-MM-dd-HH-mm-ss", Locale.US);
2387         }
2388         mCalendar.setTimeInMillis(System.currentTimeMillis());
2389         return mDateFormat.format(mCalendar.getTime());
2390     }
2391 
getFileSuffixForRequest(int profilingType)2392     private static String getFileSuffixForRequest(int profilingType) {
2393         switch (profilingType) {
2394             case ProfilingManager.PROFILING_TYPE_JAVA_HEAP_DUMP:
2395                 return OUTPUT_FILE_JAVA_HEAP_DUMP_SUFFIX;
2396             case ProfilingManager.PROFILING_TYPE_HEAP_PROFILE:
2397                 return OUTPUT_FILE_HEAP_PROFILE_SUFFIX;
2398             case ProfilingManager.PROFILING_TYPE_STACK_SAMPLING:
2399                 return OUTPUT_FILE_STACK_SAMPLING_SUFFIX;
2400             case ProfilingManager.PROFILING_TYPE_SYSTEM_TRACE:
2401                 return OUTPUT_FILE_UNREDACTED_TRACE_SUFFIX;
2402             default:
2403                 throw new IllegalArgumentException("Invalid profiling type");
2404         }
2405     }
2406 
removeInvalidFilenameChars(String original)2407     private static String removeInvalidFilenameChars(String original) {
2408         if (TextUtils.isEmpty(original)) {
2409             return "";
2410         }
2411         final StringBuilder sb = new StringBuilder(original.length());
2412         for (int i = 0; i < original.length(); i++) {
2413             final char c = Character.toLowerCase(original.charAt(i));
2414             if (isValidFilenameChar(c)) {
2415                 sb.append(c);
2416             }
2417         }
2418         return sb.toString();
2419     }
2420 
isValidFilenameChar(char c)2421     private static boolean isValidFilenameChar(char c) {
2422         if (c >= 'a' && c <= 'z') {
2423             return true;
2424         }
2425         if (c >= '0' && c <= '9') {
2426             return true;
2427         }
2428         if (c == '-') {
2429             return true;
2430         }
2431         return false;
2432     }
2433 
2434     /**
2435      * Persist service data to disk following the following rules:
2436      * - If a persist is already scheduled, do nothing.
2437      * - If a persist happened within the last {@link #mPersistFrequencyMs} then schedule a
2438      *      persist for {@link #mPersistFrequencyMs} after the last persist.
2439      * - If no persist has occurred yet or the most recent persist was more than
2440      *      {@link #mPersistFrequencyMs} ago, persist immediately.
2441      */
2442     @VisibleForTesting
maybePersistToDisk()2443     public void maybePersistToDisk() {
2444         if (!Flags.persistQueue() && !Flags.systemTriggeredProfilingNew()) {
2445             // No persisting is enabled.
2446             return;
2447         }
2448 
2449         synchronized (mLock) {
2450             if (mPersistScheduled) {
2451                 // We're already waiting on a scheduled persist job, do nothing.
2452                 return;
2453             }
2454 
2455             if (mPersistFrequencyMs.get() != 0
2456                     && (System.currentTimeMillis() - mLastPersistedTimestampMs
2457                     < mPersistFrequencyMs.get())) {
2458                 // Schedule the persist job.
2459                 if (mPersistRunnable == null) {
2460                     mPersistRunnable = new Runnable() {
2461                         @Override
2462                         public void run() {
2463                             if (Flags.persistQueue()) {
2464                                 persistQueueToDisk();
2465                             }
2466                             if (Flags.systemTriggeredProfilingNew()) {
2467                                 persistAppTriggersToDisk();
2468                             }
2469                             mPersistScheduled = false;
2470                         }
2471                     };
2472                 }
2473                 mPersistScheduled = true;
2474                 long persistDelay = mLastPersistedTimestampMs + mPersistFrequencyMs.get()
2475                         - System.currentTimeMillis();
2476                 getHandler().postDelayed(mPersistRunnable, persistDelay);
2477                 return;
2478             }
2479         }
2480 
2481         // If we got here then either persist frequency is 0 or it has already been longer than
2482         // persist frequency since the last persist. Persist immediately.
2483         if (Flags.persistQueue()) {
2484             persistQueueToDisk();
2485         }
2486         if (Flags.systemTriggeredProfilingNew()) {
2487             persistAppTriggersToDisk();
2488         }
2489     }
2490 
2491     /** Persist the current queue to disk after cleaning it up. */
2492     @VisibleForTesting
persistQueueToDisk()2493     public void persistQueueToDisk() {
2494         if (!Flags.persistQueue()) {
2495             return;
2496         }
2497 
2498         // Check if file exists
2499         try {
2500             if (mPersistQueueFile == null) {
2501                 // Try again to create the necessary files.
2502                 if (!setupPersistQueueFiles()) {
2503                     // No file, nowhere to save.
2504                     if (DEBUG) {
2505                         Log.d(TAG, "Failed setting up queue persist files so nowhere to save to.");
2506                     }
2507                     return;
2508                 }
2509             }
2510 
2511             if (!mPersistQueueFile.exists()) {
2512                 // File doesn't exist, try to create it.
2513                 mPersistQueueFile.createNewFile();
2514             }
2515         } catch (Exception e) {
2516             if (DEBUG) Log.e(TAG, "Exception accessing persisted records store.", e);
2517             return;
2518         }
2519 
2520         // Clean up queue to reduce extraneous writes
2521         maybeCleanupQueue();
2522 
2523         // Generate proto for queue.
2524         QueuedResultsWrapper.Builder builder = QueuedResultsWrapper.newBuilder();
2525 
2526         boolean recordAdded = false;
2527 
2528         for (int i = 0; i < mQueuedTracingResults.size(); i++) {
2529             List<TracingSession> perUidSessions = mQueuedTracingResults.valueAt(i);
2530             if (!perUidSessions.isEmpty()) {
2531                 for (int j = 0; j < perUidSessions.size(); j++) {
2532                     builder.addSessions(perUidSessions.get(j).toProto());
2533 
2534                     if (!recordAdded) {
2535                         recordAdded = true;
2536                     }
2537                 }
2538             }
2539         }
2540 
2541         if (!recordAdded) {
2542             // No results, nothing to persist, delete the file as it may contain results that are no
2543             // longer meaningful and will just increase future work and then return.
2544             deletePersistQueueFile();
2545             return;
2546         }
2547 
2548         QueuedResultsWrapper queuedResultsWrapper = builder.build();
2549 
2550         // Write to disk
2551         byte[] protoBytes = queuedResultsWrapper.toByteArray();
2552         AtomicFile persistFile = new AtomicFile(mPersistQueueFile);
2553         FileOutputStream out = null;
2554         try {
2555             out = persistFile.startWrite();
2556             out.write(protoBytes);
2557             persistFile.finishWrite(out);
2558             synchronized (mLock) {
2559                 mLastPersistedTimestampMs = System.currentTimeMillis();
2560             }
2561         } catch (IOException e) {
2562             if (DEBUG) Log.e(TAG, "Exception writing queued results", e);
2563             persistFile.failWrite(out);
2564         }
2565     }
2566 
2567     /** Persist the current app triggers to disk. */
2568     @VisibleForTesting
persistAppTriggersToDisk()2569     public void persistAppTriggersToDisk() {
2570         // Check if file exists
2571         try {
2572             if (mPersistAppTriggersFile == null) {
2573                 // Try again to create the necessary files.
2574                 if (!setupPersistAppTriggerFiles()) {
2575                     // No file, nowhere to save.
2576                     if (DEBUG) {
2577                         Log.d(TAG, "Failed setting up app triggers persist files so nowhere to save"
2578                                 + " to.");
2579                     }
2580                     return;
2581                 }
2582             }
2583 
2584             if (!mPersistAppTriggersFile.exists()) {
2585                 // File doesn't exist, try to create it.
2586                 mPersistAppTriggersFile.createNewFile();
2587             }
2588         } catch (Exception e) {
2589             if (DEBUG) Log.e(TAG, "Exception accessing persisted app triggers store.", e);
2590             return;
2591         }
2592 
2593         // Generate proto for queue.
2594         ProfilingTriggersWrapper.Builder builder = ProfilingTriggersWrapper.newBuilder();
2595 
2596         forEachTrigger(mAppTriggers.getMap(), (trigger) -> builder.addTriggers(trigger.toProto()));
2597 
2598         ProfilingTriggersWrapper queuedTriggersWrapper = builder.build();
2599 
2600         // Write to disk
2601         byte[] protoBytes = queuedTriggersWrapper.toByteArray();
2602         AtomicFile persistFile = new AtomicFile(mPersistAppTriggersFile);
2603         FileOutputStream out = null;
2604         try {
2605             out = persistFile.startWrite();
2606             out.write(protoBytes);
2607             persistFile.finishWrite(out);
2608             synchronized (mLock) {
2609                 mLastPersistedTimestampMs = System.currentTimeMillis();
2610             }
2611         } catch (IOException e) {
2612             if (DEBUG) Log.e(TAG, "Exception writing app triggers", e);
2613             persistFile.failWrite(out);
2614         }
2615     }
2616 
2617     /** Receive a callback with each of the tracked profiling triggers. */
forEachTrigger( ArrayMap<String, SparseArray<SparseArray<ProfilingTriggerData>>> triggersOuterMap, Consumer<ProfilingTriggerData> callback)2618     private void forEachTrigger(
2619             ArrayMap<String, SparseArray<SparseArray<ProfilingTriggerData>>> triggersOuterMap,
2620             Consumer<ProfilingTriggerData> callback) {
2621 
2622         for (int i = 0; i < triggersOuterMap.size(); i++) {
2623             SparseArray<SparseArray<ProfilingTriggerData>> triggerUidList =
2624                     triggersOuterMap.valueAt(i);
2625 
2626             for (int j = 0; j < triggerUidList.size(); j++) {
2627                 int uidKey = triggerUidList.keyAt(j);
2628                 SparseArray<ProfilingTriggerData> triggersList = triggerUidList.get(uidKey);
2629 
2630                 if (triggersList != null) {
2631                     for (int k = 0; k < triggersList.size(); k++) {
2632                         int triggerTypeKey = triggersList.keyAt(k);
2633                         ProfilingTriggerData trigger = triggersList.get(triggerTypeKey);
2634 
2635                         if (trigger != null) {
2636                             callback.accept(trigger);
2637                         }
2638                     }
2639                 }
2640             }
2641         }
2642     }
2643 
2644     /** Handle updates to test package config value. */
2645     @GuardedBy("mLock")
handleTestPackageChangeLocked(String newTestPackageName)2646     private void handleTestPackageChangeLocked(String newTestPackageName) {
2647         if (newTestPackageName == null) {
2648 
2649             // Test package has been set to null, check whether it was null previously.
2650             if (mTestPackageName != null) {
2651 
2652                 // New null state is a changed from previous state, disable test mode.
2653                 mTestPackageName = null;
2654                 stopSystemTriggeredTraceLocked();
2655             }
2656             // If new state is unchanged from previous null state, do nothing.
2657         } else {
2658 
2659             // Test package has been set with a value. Stop running system triggered trace if
2660             // applicable so we can start a new one that will have most up to date package names.
2661             // This should not be called when the new test package name matches the old one as
2662             // device config should not be sending an update for a value change when the value
2663             // remains the same, but no need to check as the best experience for caller is to always
2664             // stop the current trace and start a new one for most up to date package list.
2665             stopSystemTriggeredTraceLocked();
2666 
2667             // Now update the test package name and start the system triggered trace.
2668             mTestPackageName = newTestPackageName;
2669             startSystemTriggeredTrace();
2670         }
2671     }
2672 
2673     /**
2674      * Stop the system triggered trace.
2675      *
2676      * Locked because {link mSystemTriggeredTraceProcess} is guarded and all callers are already
2677      * locked.
2678      */
2679     @GuardedBy("mLock")
stopSystemTriggeredTraceLocked()2680     private void stopSystemTriggeredTraceLocked() {
2681         // If the trace is alive, stop it.
2682         if (mSystemTriggeredTraceProcess != null) {
2683             if (mSystemTriggeredTraceProcess.isAlive()) {
2684                 mSystemTriggeredTraceProcess.destroyForcibly();
2685             }
2686             mSystemTriggeredTraceProcess = null;
2687         }
2688 
2689         // Set session name to null.
2690         mSystemTriggeredTraceUniqueSessionName = null;
2691     }
2692 
2693     private class ProfilingDeathRecipient implements IBinder.DeathRecipient {
2694         private final int mUid;
2695 
ProfilingDeathRecipient(int uid)2696         ProfilingDeathRecipient(int uid) {
2697             mUid = uid;
2698         }
2699 
2700         @Override
binderDied()2701         public void binderDied() {
2702             if (DEBUG) Log.d(TAG, "binderDied without who should not have been called");
2703         }
2704 
2705         @Override
binderDied(IBinder who)2706         public void binderDied(IBinder who) {
2707             // Synchronize because multiple binder died callbacks may occur simultaneously
2708             // on different threads and we want to ensure that when an app dies (i.e. all
2709             // binder objects die) we attempt to stop profiling exactly once.
2710             synchronized (mLock) {
2711                 List<IProfilingResultCallback> callbacks = mResultCallbacks.get(mUid);
2712 
2713                 if (callbacks == null) {
2714                     // No callbacks list for this uid, this likely means profiling was already
2715                     // stopped (i.e. this is not the first binderDied call for this death).
2716                     return;
2717                 }
2718 
2719                 // Callbacks aren't valid anymore, remove the list.
2720                 mResultCallbacks.remove(mUid);
2721 
2722                 // Finally, attempt to stop profiling. Once the profiling is stopped, processing
2723                 // will continue as usual and will fail at copy to app storage which is the next
2724                 // step that requires the now dead binder objects. The failure will result in the
2725                 // session being added to {@link mQueueTracingResults} and being delivered to the
2726                 // app the next time it registers a general listener.
2727                 stopAllProfilingForUid(mUid);
2728             }
2729         }
2730     }
2731 
2732     public static final class Lifecycle extends SystemService {
2733         final ProfilingService mService;
2734 
Lifecycle(Context context)2735         public Lifecycle(Context context) {
2736             this(context, new ProfilingService(context));
2737         }
2738 
2739         @VisibleForTesting
Lifecycle(Context context, ProfilingService service)2740         public Lifecycle(Context context, ProfilingService service) {
2741             super(context);
2742             mService = service;
2743         }
2744 
2745         @Override
onStart()2746         public void onStart() {
2747             try {
2748                 publishBinderService("profiling_service", mService);
2749             } catch (Exception e) {
2750                 if (DEBUG) Log.d(TAG, "Failed to publish service", e);
2751             }
2752         }
2753 
2754         @Override
onBootPhase(int phase)2755         public void onBootPhase(int phase) {
2756             super.onBootPhase(phase);
2757         }
2758     }
2759 }
2760