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