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.EventLog; |
Alan Stokes | be9ec97 | 2018-12-10 14:07:47 +0000 | [diff] [blame] | 28 | import android.util.Log; |
| 29 | |
Alan Stokes | 96efc028 | 2019-02-05 15:10:36 +0000 | [diff] [blame] | 30 | import com.android.server.pm.dex.DynamicCodeLogger; |
Alan Stokes | be9ec97 | 2018-12-10 14:07:47 +0000 | [diff] [blame] | 31 | |
Neil Fuller | e3a9212 | 2019-04-11 11:57:28 +0100 | [diff] [blame] | 32 | import libcore.util.HexEncoding; |
| 33 | |
Alan Stokes | e9d3314 | 2018-12-19 09:31:21 +0000 | [diff] [blame] | 34 | import java.util.ArrayList; |
| 35 | import java.util.List; |
Alan Stokes | be9ec97 | 2018-12-10 14:07:47 +0000 | [diff] [blame] | 36 | import java.util.concurrent.TimeUnit; |
Alan Stokes | e9d3314 | 2018-12-19 09:31:21 +0000 | [diff] [blame] | 37 | import java.util.regex.Matcher; |
| 38 | import java.util.regex.Pattern; |
Alan Stokes | be9ec97 | 2018-12-10 14:07:47 +0000 | [diff] [blame] | 39 | |
| 40 | /** |
Alan Stokes | e9d3314 | 2018-12-19 09:31:21 +0000 | [diff] [blame] | 41 | * 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] | 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}. |
Alan Stokes | be9ec97 | 2018-12-10 14:07:47 +0000 | [diff] [blame] | 46 | * {@hide} |
| 47 | */ |
| 48 | public class DynamicCodeLoggingService extends JobService { |
| 49 | private static final String TAG = DynamicCodeLoggingService.class.getName(); |
| 50 | |
Alan Stokes | be9ec97 | 2018-12-10 14:07:47 +0000 | [diff] [blame] | 51 | private static final boolean DEBUG = false; |
| 52 | |
Alan Stokes | e9d3314 | 2018-12-19 09:31:21 +0000 | [diff] [blame] | 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]+)) .*" |
Alan Stokes | fc9a21d | 2019-02-27 21:30:59 +0000 | [diff] [blame] | 65 | + "\\bscontext=u:r:untrusted_app(?:_25|_27)?:.*" |
Alan Stokes | e9d3314 | 2018-12-19 09:31:21 +0000 | [diff] [blame] | 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 | |
Alan Stokes | be9ec97 | 2018-12-10 14:07:47 +0000 | [diff] [blame] | 72 | /** |
Alan Stokes | e9d3314 | 2018-12-19 09:31:21 +0000 | [diff] [blame] | 73 | * Schedule our jobs with the {@link JobScheduler}. |
Alan Stokes | be9ec97 | 2018-12-10 14:07:47 +0000 | [diff] [blame] | 74 | */ |
| 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); |
Alan Stokes | e9d3314 | 2018-12-19 09:31:21 +0000 | [diff] [blame] | 80 | js.schedule(new JobInfo.Builder(IDLE_LOGGING_JOB_ID, serviceName) |
Alan Stokes | be9ec97 | 2018-12-10 14:07:47 +0000 | [diff] [blame] | 81 | .setRequiresDeviceIdle(true) |
| 82 | .setRequiresCharging(true) |
Alan Stokes | e9d3314 | 2018-12-19 09:31:21 +0000 | [diff] [blame] | 83 | .setPeriodic(IDLE_LOGGING_PERIOD_MILLIS) |
Alan Stokes | be9ec97 | 2018-12-10 14:07:47 +0000 | [diff] [blame] | 84 | .build()); |
Alan Stokes | e9d3314 | 2018-12-19 09:31:21 +0000 | [diff] [blame] | 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 | |
Alan Stokes | be9ec97 | 2018-12-10 14:07:47 +0000 | [diff] [blame] | 91 | if (DEBUG) { |
Alan Stokes | e9d3314 | 2018-12-19 09:31:21 +0000 | [diff] [blame] | 92 | Log.d(TAG, "Jobs scheduled"); |
Alan Stokes | be9ec97 | 2018-12-10 14:07:47 +0000 | [diff] [blame] | 93 | } |
| 94 | } |
| 95 | |
| 96 | @Override |
| 97 | public boolean onStartJob(JobParameters params) { |
Alan Stokes | e9d3314 | 2018-12-19 09:31:21 +0000 | [diff] [blame] | 98 | int jobId = params.getJobId(); |
Alan Stokes | be9ec97 | 2018-12-10 14:07:47 +0000 | [diff] [blame] | 99 | if (DEBUG) { |
Alan Stokes | e9d3314 | 2018-12-19 09:31:21 +0000 | [diff] [blame] | 100 | Log.d(TAG, "onStartJob " + jobId); |
Alan Stokes | be9ec97 | 2018-12-10 14:07:47 +0000 | [diff] [blame] | 101 | } |
Alan Stokes | e9d3314 | 2018-12-19 09:31:21 +0000 | [diff] [blame] | 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 | } |
Alan Stokes | be9ec97 | 2018-12-10 14:07:47 +0000 | [diff] [blame] | 115 | } |
| 116 | |
| 117 | @Override |
| 118 | public boolean onStopJob(JobParameters params) { |
Alan Stokes | e9d3314 | 2018-12-19 09:31:21 +0000 | [diff] [blame] | 119 | int jobId = params.getJobId(); |
Alan Stokes | be9ec97 | 2018-12-10 14:07:47 +0000 | [diff] [blame] | 120 | if (DEBUG) { |
Alan Stokes | e9d3314 | 2018-12-19 09:31:21 +0000 | [diff] [blame] | 121 | Log.d(TAG, "onStopJob " + jobId); |
Alan Stokes | be9ec97 | 2018-12-10 14:07:47 +0000 | [diff] [blame] | 122 | } |
Alan Stokes | e9d3314 | 2018-12-19 09:31:21 +0000 | [diff] [blame] | 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 | |
Alan Stokes | 96efc028 | 2019-02-05 15:10:36 +0000 | [diff] [blame] | 135 | private static DynamicCodeLogger getDynamicCodeLogger() { |
Alan Stokes | e9d3314 | 2018-12-19 09:31:21 +0000 | [diff] [blame] | 136 | PackageManagerService pm = (PackageManagerService) ServiceManager.getService("package"); |
Alan Stokes | 96efc028 | 2019-02-05 15:10:36 +0000 | [diff] [blame] | 137 | return pm.getDexManager().getDynamicCodeLogger(); |
Alan Stokes | be9ec97 | 2018-12-10 14:07:47 +0000 | [diff] [blame] | 138 | } |
| 139 | |
| 140 | private class IdleLoggingThread extends Thread { |
| 141 | private final JobParameters mParams; |
| 142 | |
| 143 | IdleLoggingThread(JobParameters params) { |
| 144 | super("DynamicCodeLoggingService_IdleLoggingJob"); |
| 145 | mParams = params; |
| 146 | } |
| 147 | |
| 148 | @Override |
| 149 | public void run() { |
| 150 | if (DEBUG) { |
Alan Stokes | e9d3314 | 2018-12-19 09:31:21 +0000 | [diff] [blame] | 151 | Log.d(TAG, "Starting IdleLoggingJob run"); |
Alan Stokes | be9ec97 | 2018-12-10 14:07:47 +0000 | [diff] [blame] | 152 | } |
| 153 | |
Alan Stokes | 96efc028 | 2019-02-05 15:10:36 +0000 | [diff] [blame] | 154 | DynamicCodeLogger dynamicCodeLogger = getDynamicCodeLogger(); |
| 155 | for (String packageName : dynamicCodeLogger.getAllPackagesWithDynamicCodeLoading()) { |
Alan Stokes | e9d3314 | 2018-12-19 09:31:21 +0000 | [diff] [blame] | 156 | if (mIdleLoggingStopRequested) { |
| 157 | Log.w(TAG, "Stopping IdleLoggingJob run at scheduler request"); |
Alan Stokes | be9ec97 | 2018-12-10 14:07:47 +0000 | [diff] [blame] | 158 | return; |
| 159 | } |
| 160 | |
Alan Stokes | 96efc028 | 2019-02-05 15:10:36 +0000 | [diff] [blame] | 161 | dynamicCodeLogger.logDynamicCodeLoading(packageName); |
Alan Stokes | be9ec97 | 2018-12-10 14:07:47 +0000 | [diff] [blame] | 162 | } |
| 163 | |
| 164 | jobFinished(mParams, /* reschedule */ false); |
| 165 | if (DEBUG) { |
Alan Stokes | e9d3314 | 2018-12-19 09:31:21 +0000 | [diff] [blame] | 166 | Log.d(TAG, "Finished IdleLoggingJob run"); |
Alan Stokes | be9ec97 | 2018-12-10 14:07:47 +0000 | [diff] [blame] | 167 | } |
| 168 | } |
| 169 | } |
Alan Stokes | e9d3314 | 2018-12-19 09:31:21 +0000 | [diff] [blame] | 170 | |
| 171 | private class AuditWatchingThread extends Thread { |
| 172 | private final JobParameters mParams; |
| 173 | |
| 174 | AuditWatchingThread(JobParameters params) { |
| 175 | super("DynamicCodeLoggingService_AuditWatchingJob"); |
| 176 | mParams = params; |
| 177 | } |
| 178 | |
| 179 | @Override |
| 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 | |
| 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 |
Alan Stokes | 96efc028 | 2019-02-05 15:10:36 +0000 | [diff] [blame] | 196 | // file. Matches are recorded in DynamicCodeLogger. |
Alan Stokes | e9d3314 | 2018-12-19 09:31:21 +0000 | [diff] [blame] | 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 |
Alan Stokes | 96efc028 | 2019-02-05 15:10:36 +0000 | [diff] [blame] | 218 | // by DynamicCodeLogger. |
Alan Stokes | e9d3314 | 2018-12-19 09:31:21 +0000 | [diff] [blame] | 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 | |
Alan Stokes | 96efc028 | 2019-02-05 15:10:36 +0000 | [diff] [blame] | 233 | DynamicCodeLogger dynamicCodeLogger = getDynamicCodeLogger(); |
Alan Stokes | e9d3314 | 2018-12-19 09:31:21 +0000 | [diff] [blame] | 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 | } |
Alan Stokes | 96efc028 | 2019-02-05 15:10:36 +0000 | [diff] [blame] | 272 | dynamicCodeLogger.recordNative(uid, path); |
Alan Stokes | e9d3314 | 2018-12-19 09:31:21 +0000 | [diff] [blame] | 273 | } |
| 274 | |
| 275 | return true; |
| 276 | } catch (Exception e) { |
| 277 | Log.e(TAG, "AuditWatchingJob failed", e); |
| 278 | return true; |
| 279 | } |
| 280 | } |
| 281 | } |
| 282 | |
| 283 | private static String unhex(String hexEncodedPath) { |
Neil Fuller | e3a9212 | 2019-04-11 11:57:28 +0100 | [diff] [blame] | 284 | if (hexEncodedPath == null || hexEncodedPath.length() == 0) { |
Alan Stokes | e9d3314 | 2018-12-19 09:31:21 +0000 | [diff] [blame] | 285 | return ""; |
| 286 | } |
Neil Fuller | e3a9212 | 2019-04-11 11:57:28 +0100 | [diff] [blame] | 287 | byte[] bytes = HexEncoding.decode(hexEncodedPath, false /* allowSingleChar */); |
Alan Stokes | e9d3314 | 2018-12-19 09:31:21 +0000 | [diff] [blame] | 288 | return new String(bytes); |
| 289 | } |
Alan Stokes | be9ec97 | 2018-12-10 14:07:47 +0000 | [diff] [blame] | 290 | } |