1 /*
2  * Copyright 2018 The Android Open Source Project
3  *
4  * Licensed under the Apache License, Version 2.0 (the "License");
5  * you may not use this file except in compliance with the License.
6  * You may obtain a copy of the License at
7  *
8  *      http://www.apache.org/licenses/LICENSE-2.0
9  *
10  * Unless required by applicable law or agreed to in writing, software
11  * distributed under the License is distributed on an "AS IS" BASIS,
12  * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13  * See the License for the specific language governing permissions and
14  * limitations under the License.
15  */
16 
17 package com.android.server.pm;
18 
19 import android.app.job.JobInfo;
20 import android.app.job.JobParameters;
21 import android.app.job.JobScheduler;
22 import android.app.job.JobService;
23 import android.content.ComponentName;
24 import android.content.Context;
25 import android.content.pm.PackageManagerInternal;
26 import android.os.Process;
27 import android.util.EventLog;
28 import android.util.Log;
29 
30 import com.android.server.LocalManagerRegistry;
31 import com.android.server.LocalServices;
32 import com.android.server.art.DexUseManagerLocal;
33 import com.android.server.art.model.DexContainerFileUseInfo;
34 import com.android.server.pm.dex.DynamicCodeLogger;
35 
36 import libcore.util.HexEncoding;
37 
38 import java.util.ArrayList;
39 import java.util.List;
40 import java.util.Objects;
41 import java.util.concurrent.TimeUnit;
42 import java.util.regex.Matcher;
43 import java.util.regex.Pattern;
44 
45 /**
46  * Scheduled jobs related to logging of app dynamic code loading. The idle logging job runs daily
47  * while idle and charging  and calls {@link DynamicCodeLogger} to write dynamic code information
48  * to the event log. The audit watching job scans the event log periodically while idle to find AVC
49  * audit messages indicating use of dynamic native code and adds the information to
50  * {@link DynamicCodeLogger}.
51  * {@hide}
52  */
53 public class DynamicCodeLoggingService extends JobService {
54     private static final String TAG = DynamicCodeLoggingService.class.getName();
55 
56     private static final boolean DEBUG = false;
57 
58     private static final int IDLE_LOGGING_JOB_ID = 2030028;
59     private static final int AUDIT_WATCHING_JOB_ID = 203142925;
60 
61     private static final long IDLE_LOGGING_PERIOD_MILLIS = TimeUnit.DAYS.toMillis(1);
62     private static final long AUDIT_WATCHING_PERIOD_MILLIS = TimeUnit.HOURS.toMillis(2);
63 
64     private static final int AUDIT_AVC = 1400;  // Defined in linux/audit.h
65     private static final String AVC_PREFIX = "type=" + AUDIT_AVC + " ";
66 
67     private static final Pattern EXECUTE_NATIVE_AUDIT_PATTERN =
68             Pattern.compile(".*\\bavc: +granted +\\{ execute(?:_no_trans|) \\} .*"
69                     + "\\bpath=(?:\"([^\" ]*)\"|([0-9A-F]+)) .*"
70                     + "\\bscontext=u:r:untrusted_app(?:_25|_27)?:.*"
71                     + "\\btcontext=u:object_r:app_data_file:.*"
72                     + "\\btclass=file\\b.*");
73 
74     private volatile boolean mIdleLoggingStopRequested = false;
75     private volatile boolean mAuditWatchingStopRequested = false;
76 
77     /**
78      * Schedule our jobs with the {@link JobScheduler}.
79      */
schedule(Context context)80     public static void schedule(Context context) {
81         ComponentName serviceName = new ComponentName(
82                 "android", DynamicCodeLoggingService.class.getName());
83 
84         JobScheduler js = (JobScheduler) context.getSystemService(Context.JOB_SCHEDULER_SERVICE);
85         js.schedule(new JobInfo.Builder(IDLE_LOGGING_JOB_ID, serviceName)
86                 .setRequiresDeviceIdle(true)
87                 .setRequiresCharging(true)
88                 .setPeriodic(IDLE_LOGGING_PERIOD_MILLIS)
89                 .build());
90         js.schedule(new JobInfo.Builder(AUDIT_WATCHING_JOB_ID, serviceName)
91                 .setRequiresDeviceIdle(true)
92                 .setRequiresBatteryNotLow(true)
93                 .setPeriodic(AUDIT_WATCHING_PERIOD_MILLIS)
94                 .build());
95 
96         if (DEBUG) {
97             Log.d(TAG, "Jobs scheduled");
98         }
99     }
100 
101     @Override
onStartJob(JobParameters params)102     public boolean onStartJob(JobParameters params) {
103         int jobId = params.getJobId();
104         if (DEBUG) {
105             Log.d(TAG, "onStartJob " + jobId);
106         }
107         switch (jobId) {
108             case IDLE_LOGGING_JOB_ID:
109                 mIdleLoggingStopRequested = false;
110                 new IdleLoggingThread(params).start();
111                 return true;  // Job is running on another thread
112             case AUDIT_WATCHING_JOB_ID:
113                 mAuditWatchingStopRequested = false;
114                 new AuditWatchingThread(params).start();
115                 return true;  // Job is running on another thread
116             default:
117                 // Shouldn't happen, but indicate nothing is running.
118                 return false;
119         }
120     }
121 
122     @Override
onStopJob(JobParameters params)123     public boolean onStopJob(JobParameters params) {
124         int jobId = params.getJobId();
125         if (DEBUG) {
126             Log.d(TAG, "onStopJob " + jobId);
127         }
128         switch (jobId) {
129             case IDLE_LOGGING_JOB_ID:
130                 mIdleLoggingStopRequested = true;
131                 return true;  // Requests job be re-scheduled.
132             case AUDIT_WATCHING_JOB_ID:
133                 mAuditWatchingStopRequested = true;
134                 return true;  // Requests job be re-scheduled.
135             default:
136                 return false;
137         }
138     }
139 
getDynamicCodeLogger()140     private static DynamicCodeLogger getDynamicCodeLogger() {
141         return LocalServices.getService(PackageManagerInternal.class).getDynamicCodeLogger();
142     }
143 
syncDataFromArtService(DynamicCodeLogger dynamicCodeLogger)144     private static void syncDataFromArtService(DynamicCodeLogger dynamicCodeLogger) {
145         DexUseManagerLocal dexUseManagerLocal = DexOptHelper.getDexUseManagerLocal();
146         if (dexUseManagerLocal == null) {
147             // ART Service is not enabled.
148             return;
149         }
150         PackageManagerLocal packageManagerLocal =
151                 Objects.requireNonNull(LocalManagerRegistry.getManager(PackageManagerLocal.class));
152         try (PackageManagerLocal.UnfilteredSnapshot snapshot =
153                         packageManagerLocal.withUnfilteredSnapshot()) {
154             for (String owningPackageName : snapshot.getPackageStates().keySet()) {
155                 for (DexContainerFileUseInfo info :
156                         dexUseManagerLocal.getSecondaryDexContainerFileUseInfo(owningPackageName)) {
157                     for (String loadingPackageName : info.getLoadingPackages()) {
158                         dynamicCodeLogger.recordDex(info.getUserHandle().getIdentifier(),
159                                 info.getDexContainerFile(), owningPackageName, loadingPackageName);
160                     }
161                 }
162             }
163         }
164     }
165 
166     private class IdleLoggingThread extends Thread {
167         private final JobParameters mParams;
168 
IdleLoggingThread(JobParameters params)169         IdleLoggingThread(JobParameters params) {
170             super("DynamicCodeLoggingService_IdleLoggingJob");
171             mParams = params;
172         }
173 
174         @Override
run()175         public void run() {
176             if (DEBUG) {
177                 Log.d(TAG, "Starting IdleLoggingJob run");
178             }
179 
180             DynamicCodeLogger dynamicCodeLogger = getDynamicCodeLogger();
181             syncDataFromArtService(dynamicCodeLogger);
182             for (String packageName : dynamicCodeLogger.getAllPackagesWithDynamicCodeLoading()) {
183                 if (mIdleLoggingStopRequested) {
184                     Log.w(TAG, "Stopping IdleLoggingJob run at scheduler request");
185                     return;
186                 }
187 
188                 dynamicCodeLogger.logDynamicCodeLoading(packageName);
189             }
190 
191             jobFinished(mParams, /* reschedule */ false);
192             if (DEBUG) {
193                 Log.d(TAG, "Finished IdleLoggingJob run");
194             }
195         }
196     }
197 
198     private class AuditWatchingThread extends Thread {
199         private final JobParameters mParams;
200 
AuditWatchingThread(JobParameters params)201         AuditWatchingThread(JobParameters params) {
202             super("DynamicCodeLoggingService_AuditWatchingJob");
203             mParams = params;
204         }
205 
206         @Override
run()207         public void run() {
208             if (DEBUG) {
209                 Log.d(TAG, "Starting AuditWatchingJob run");
210             }
211 
212             if (processAuditEvents()) {
213                 jobFinished(mParams, /* reschedule */ false);
214                 if (DEBUG) {
215                     Log.d(TAG, "Finished AuditWatchingJob run");
216                 }
217             }
218         }
219 
processAuditEvents()220         private boolean processAuditEvents() {
221             // Scan the event log for SELinux (avc) audit messages indicating when an
222             // (untrusted) app has executed native code from an app data
223             // file. Matches are recorded in DynamicCodeLogger.
224             //
225             // These messages come from the kernel audit system via logd. (Note that
226             // some devices may not generate these messages at all, or the format may
227             // be different, in which case nothing will be recorded.)
228             //
229             // The messages use the auditd tag and the uid of the app that executed
230             // the code.
231             //
232             // A typical message might look like this:
233             // type=1400 audit(0.0:521): avc: granted { execute } for comm="executable"
234             //  path="/data/data/com.placeholder.app/executable" dev="sda13" ino=1655302
235             //  scontext=u:r:untrusted_app_27:s0:c66,c257,c512,c768
236             //  tcontext=u:object_r:app_data_file:s0:c66,c257,c512,c768 tclass=file
237             //
238             // The information we want is the uid and the path. (Note this may be
239             // either a quoted string, as shown above, or a sequence of hex-encoded
240             // bytes.)
241             //
242             // On each run we process all the matching events in the log. This may
243             // mean re-processing events we have already seen, and in any case there
244             // may be duplicate events for the same app+file. These are de-duplicated
245             // by DynamicCodeLogger.
246             //
247             // Note that any app can write a message to the event log, including one
248             // that looks exactly like an AVC audit message, so the information may
249             // be spoofed by an app; in such a case the uid we see will be the app
250             // that generated the spoof message.
251 
252             try {
253                 int[] tags = { EventLog.getTagCode("auditd") };
254                 if (tags[0] == -1) {
255                     // auditd is not a registered tag on this system, so there can't be any messages
256                     // of interest.
257                     return true;
258                 }
259 
260                 DynamicCodeLogger dynamicCodeLogger = getDynamicCodeLogger();
261 
262                 List<EventLog.Event> events = new ArrayList<>();
263                 EventLog.readEvents(tags, events);
264                 Matcher matcher = EXECUTE_NATIVE_AUDIT_PATTERN.matcher("");
265                 for (int i = 0; i < events.size(); ++i) {
266                     if (mAuditWatchingStopRequested) {
267                         Log.w(TAG, "Stopping AuditWatchingJob run at scheduler request");
268                         return false;
269                     }
270 
271                     EventLog.Event event = events.get(i);
272 
273                     // Discard clearly unrelated messages as quickly as we can.
274                     int uid = event.getUid();
275                     if (!Process.isApplicationUid(uid)) {
276                         continue;
277                     }
278                     Object data = event.getData();
279                     if (!(data instanceof String)) {
280                         continue;
281                     }
282                     String message = (String) data;
283                     if (!message.startsWith(AVC_PREFIX)) {
284                         continue;
285                     }
286 
287                     // And then use a regular expression to verify it's one of the messages we're
288                     // interested in and to extract the path of the file being loaded.
289                     // Reuse the Matcher to avoid unnecessary string garbage caused by libcore's
290                     // regex matching.
291                     matcher.reset(message);
292                     if (!matcher.matches()) {
293                         continue;
294                     }
295                     String path = matcher.group(1);
296                     if (path == null) {
297                         // If the path contains spaces or various weird characters the kernel
298                         // hex-encodes the bytes; we need to undo that.
299                         path = unhex(matcher.group(2));
300                     }
301                     dynamicCodeLogger.recordNative(uid, path);
302                 }
303 
304                 return true;
305             } catch (Exception e) {
306                 Log.e(TAG, "AuditWatchingJob failed", e);
307                 return true;
308             }
309         }
310     }
311 
unhex(String hexEncodedPath)312     private static String unhex(String hexEncodedPath) {
313         if (hexEncodedPath == null || hexEncodedPath.length() == 0) {
314             return "";
315         }
316         byte[] bytes = HexEncoding.decode(hexEncodedPath, false /* allowSingleChar */);
317         return new String(bytes);
318     }
319 }
320