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