Android/frameworks_base
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

Merge "Separate job service for dynamic code logging."

Browse Source
This commit is contained in:
Alan Stokes
2018-12-13 15:28:37 +00:00
committed by Android (Google) Code Review
parent e9509a3215 be9ec976c5
commit 809ada2840
9 changed files with 613 additions and 225 deletions
Download Patch File Download Diff File Expand all files Collapse all files

4
core/res/AndroidManifest.xml
View File

@@ -4696,6 +4696,10 @@
android:permission="android.permission.BIND_JOB_SERVICE">
</service>
<service android:name="com.android.server.pm.DynamicCodeLoggingService"
android:permission="android.permission.BIND_JOB_SERVICE">
</service>
<service android:name="com.android.server.PruneInstantAppsJobService"
android:permission="android.permission.BIND_JOB_SERVICE" >
</service>

115
services/core/java/com/android/server/pm/DynamicCodeLoggingService.java Normal file
View File

@@ -0,0 +1,115 @@
/*
* Copyright 2018 The Android Open Source Project
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing, software
* distributed under the License is distributed on an "AS IS" BASIS,
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
* See the License for the specific language governing permissions and
* limitations under the License.
*/
package com.android.server.pm;
import android.app.job.JobInfo;
import android.app.job.JobParameters;
import android.app.job.JobScheduler;
import android.app.job.JobService;
import android.content.ComponentName;
import android.content.Context;
import android.os.ServiceManager;
import android.util.Log;
import com.android.server.pm.dex.DexLogger;
import java.util.concurrent.TimeUnit;
/**
* Scheduled job to trigger logging of app dynamic code loading. This runs daily while idle and
* charging. The actual logging is performed by {@link DexLogger}.
* {@hide}
*/
public class DynamicCodeLoggingService extends JobService {
private static final String TAG = DynamicCodeLoggingService.class.getName();
private static final int JOB_ID = 2030028;
private static final long PERIOD_MILLIS = TimeUnit.DAYS.toMillis(1);
private volatile boolean mStopRequested = false;
private static final boolean DEBUG = false;
/**
* Schedule our job with the {@link JobScheduler}.
*/
public static void schedule(Context context) {
ComponentName serviceName = new ComponentName(
"android", DynamicCodeLoggingService.class.getName());
JobScheduler js = (JobScheduler) context.getSystemService(Context.JOB_SCHEDULER_SERVICE);
js.schedule(new JobInfo.Builder(JOB_ID, serviceName)
.setRequiresDeviceIdle(true)
.setRequiresCharging(true)
.setPeriodic(PERIOD_MILLIS)
.build());
if (DEBUG) {
Log.d(TAG, "Job scheduled");
}
}
@Override
public boolean onStartJob(JobParameters params) {
if (DEBUG) {
Log.d(TAG, "onStartJob");
}
mStopRequested = false;
new IdleLoggingThread(params).start();
return true; // Job is running on another thread
}
@Override
public boolean onStopJob(JobParameters params) {
if (DEBUG) {
Log.d(TAG, "onStopJob");
}
mStopRequested = true;
return true; // Requests job be re-scheduled.
}
private class IdleLoggingThread extends Thread {
private final JobParameters mParams;
IdleLoggingThread(JobParameters params) {
super("DynamicCodeLoggingService_IdleLoggingJob");
mParams = params;
}
@Override
public void run() {
if (DEBUG) {
Log.d(TAG, "Starting logging run");
}
PackageManagerService pm = (PackageManagerService) ServiceManager.getService("package");
DexLogger dexLogger = pm.getDexManager().getDexLogger();
for (String packageName : dexLogger.getAllPackagesWithDynamicCodeLoading()) {
if (mStopRequested) {
Log.w(TAG, "Stopping logging run at scheduler request");
return;
}
dexLogger.logDynamicCodeLoading(packageName);
}
jobFinished(mParams, /* reschedule */ false);
if (DEBUG) {
Log.d(TAG, "Finished logging run");
}
}
}
}

8
services/core/java/com/android/server/pm/PackageManagerService.java
View File

@@ -304,7 +304,6 @@ import com.android.server.pm.Installer.InstallerException;
import com.android.server.pm.Settings.DatabaseVersion;
import com.android.server.pm.Settings.VersionInfo;
import com.android.server.pm.dex.ArtManagerService;
import com.android.server.pm.dex.DexLogger;
import com.android.server.pm.dex.DexManager;
import com.android.server.pm.dex.DexoptOptions;
import com.android.server.pm.dex.PackageDexUsage;
@@ -2168,10 +2167,7 @@ public class PackageManagerService extends IPackageManager.Stub
mPackageDexOptimizer = new PackageDexOptimizer(installer, mInstallLock, context,
"*dexopt*");
DexManager.Listener dexManagerListener = DexLogger.getListener(this,
installer, mInstallLock);
mDexManager = new DexManager(mContext, this, mPackageDexOptimizer, installer, mInstallLock,
dexManagerListener);
mDexManager = new DexManager(mContext, this, mPackageDexOptimizer, installer, mInstallLock);
mArtManagerService = new ArtManagerService(mContext, this, installer, mInstallLock);
mMoveCallbacks = new MoveCallbacks(FgThread.get().getLooper());
@@ -9215,7 +9211,7 @@ public class PackageManagerService extends IPackageManager.Stub
/**
* Reconcile the information we have about the secondary dex files belonging to
* {@code packagName} and the actual dex files. For all dex files that were
* {@code packageName} and the actual dex files. For all dex files that were
* deleted, update the internal records and delete the generated oat files.
*/
@Override

194
services/core/java/com/android/server/pm/dex/DexLogger.java
View File

@@ -18,29 +18,32 @@ package com.android.server.pm.dex;
import android.content.pm.ApplicationInfo;
import android.content.pm.IPackageManager;
import android.content.pm.PackageInfo;
import android.os.FileUtils;
import android.os.RemoteException;
import android.util.ArraySet;
import android.os.storage.StorageManager;
import android.util.ByteStringUtils;
import android.util.EventLog;
import android.util.PackageUtils;
import android.util.Slog;
import android.util.SparseArray;
import com.android.internal.annotations.GuardedBy;
import com.android.internal.annotations.VisibleForTesting;
import com.android.server.pm.Installer;
import com.android.server.pm.Installer.InstallerException;
import com.android.server.pm.dex.PackageDynamicCodeLoading.DynamicCodeFile;
import com.android.server.pm.dex.PackageDynamicCodeLoading.PackageDynamicCode;
import java.io.File;
import java.util.Map;
import java.util.Set;
import static com.android.server.pm.dex.PackageDexUsage.DexUseInfo;
/**
* This class is responsible for logging data about secondary dex files.
* The data logged includes hashes of the name and content of each file.
*/
public class DexLogger implements DexManager.Listener {
public class DexLogger {
private static final String TAG = "DexLogger";
// Event log tag & subtag used for SafetyNet logging of dynamic
@@ -49,75 +52,172 @@ public class DexLogger implements DexManager.Listener {
private static final String DCL_SUBTAG = "dcl";
private final IPackageManager mPackageManager;
private final PackageDynamicCodeLoading mPackageDynamicCodeLoading;
private final Object mInstallLock;
@GuardedBy("mInstallLock")
private final Installer mInstaller;
public static DexManager.Listener getListener(IPackageManager pms,
Installer installer, Object installLock) {
return new DexLogger(pms, installer, installLock);
public DexLogger(IPackageManager pms, Installer installer, Object installLock) {
this(pms, installer, installLock, new PackageDynamicCodeLoading());
}
@VisibleForTesting
/*package*/ DexLogger(IPackageManager pms, Installer installer, Object installLock) {
DexLogger(IPackageManager pms, Installer installer, Object installLock,
PackageDynamicCodeLoading packageDynamicCodeLoading) {
mPackageManager = pms;
mPackageDynamicCodeLoading = packageDynamicCodeLoading;
mInstaller = installer;
mInstallLock = installLock;
}
/**
* Compute and log hashes of the name and content of a secondary dex file.
*/
@Override
public void onReconcileSecondaryDexFile(ApplicationInfo appInfo, DexUseInfo dexUseInfo,
String dexPath, int storageFlags) {
int ownerUid = appInfo.uid;
public Set<String> getAllPackagesWithDynamicCodeLoading() {
return mPackageDynamicCodeLoading.getAllPackagesWithDynamicCodeLoading();
}
byte[] hash = null;
synchronized(mInstallLock) {
try {
hash = mInstaller.hashSecondaryDexFile(dexPath, appInfo.packageName,
ownerUid, appInfo.volumeUuid, storageFlags);
} catch (InstallerException e) {
Slog.e(TAG, "Got InstallerException when hashing dex " + dexPath +
" : " + e.getMessage());
}
}
if (hash == null) {
/**
* Write information about code dynamically loaded by {@code packageName} to the event log.
*/
public void logDynamicCodeLoading(String packageName) {
PackageDynamicCode info = getPackageDynamicCodeInfo(packageName);
if (info == null) {
return;
}
String dexFileName = new File(dexPath).getName();
String message = PackageUtils.computeSha256Digest(dexFileName.getBytes());
// Valid SHA256 will be 256 bits, 32 bytes.
if (hash.length == 32) {
message = message + ' ' + ByteStringUtils.toHexString(hash);
}
SparseArray<ApplicationInfo> appInfoByUser = new SparseArray<>();
boolean needWrite = false;
writeDclEvent(ownerUid, message);
for (Map.Entry<String, DynamicCodeFile> fileEntry : info.mFileUsageMap.entrySet()) {
String filePath = fileEntry.getKey();
DynamicCodeFile fileInfo = fileEntry.getValue();
int userId = fileInfo.mUserId;
int index = appInfoByUser.indexOfKey(userId);
ApplicationInfo appInfo;
if (index >= 0) {
appInfo = appInfoByUser.get(userId);
} else {
appInfo = null;
if (dexUseInfo.isUsedByOtherApps()) {
Set<String> otherPackages = dexUseInfo.getLoadingPackages();
Set<Integer> otherUids = new ArraySet<>(otherPackages.size());
for (String otherPackageName : otherPackages) {
try {
int otherUid = mPackageManager.getPackageUid(
otherPackageName, /*flags*/0, dexUseInfo.getOwnerUserId());
if (otherUid != -1 && otherUid != ownerUid) {
otherUids.add(otherUid);
}
} catch (RemoteException ignore) {
PackageInfo ownerInfo =
mPackageManager.getPackageInfo(packageName, /*flags*/ 0, userId);
appInfo = ownerInfo == null ? null : ownerInfo.applicationInfo;
} catch (RemoteException ignored) {
// Can't happen, we're local.
}
appInfoByUser.put(userId, appInfo);
if (appInfo == null) {
Slog.d(TAG, "Could not find package " + packageName + " for user " + userId);
// Package has probably been uninstalled for user.
needWrite |= mPackageDynamicCodeLoading.removeUserPackage(packageName, userId);
}
}
for (int otherUid : otherUids) {
writeDclEvent(otherUid, message);
if (appInfo == null) {
continue;
}
int storageFlags;
if (appInfo.deviceProtectedDataDir != null
&& FileUtils.contains(appInfo.deviceProtectedDataDir, filePath)) {
storageFlags = StorageManager.FLAG_STORAGE_DE;
} else if (appInfo.credentialProtectedDataDir != null
&& FileUtils.contains(appInfo.credentialProtectedDataDir, filePath)) {
storageFlags = StorageManager.FLAG_STORAGE_CE;
} else {
Slog.e(TAG, "Could not infer CE/DE storage for path " + filePath);
needWrite |= mPackageDynamicCodeLoading.removeFile(packageName, filePath, userId);
continue;
}
byte[] hash = null;
synchronized (mInstallLock) {
try {
hash = mInstaller.hashSecondaryDexFile(filePath, packageName, appInfo.uid,
appInfo.volumeUuid, storageFlags);
} catch (InstallerException e) {
Slog.e(TAG, "Got InstallerException when hashing file " + filePath
+ ": " + e.getMessage());
}
}
String fileName = new File(filePath).getName();
String message = PackageUtils.computeSha256Digest(fileName.getBytes());
// Valid SHA256 will be 256 bits, 32 bytes.
if (hash != null && hash.length == 32) {
message = message + ' ' + ByteStringUtils.toHexString(hash);
} else {
Slog.d(TAG, "Got no hash for " + filePath);
// File has probably been deleted.
needWrite |= mPackageDynamicCodeLoading.removeFile(packageName, filePath, userId);
}
for (String loadingPackageName : fileInfo.mLoadingPackages) {
int loadingUid = -1;
if (loadingPackageName.equals(packageName)) {
loadingUid = appInfo.uid;
} else {
try {
loadingUid = mPackageManager.getPackageUid(loadingPackageName, /*flags*/ 0,
userId);
} catch (RemoteException ignored) {
// Can't happen, we're local.
}
}
if (loadingUid != -1) {
writeDclEvent(loadingUid, message);
}
}
}
if (needWrite) {
mPackageDynamicCodeLoading.maybeWriteAsync();
}
}
@VisibleForTesting
/*package*/ void writeDclEvent(int uid, String message) {
PackageDynamicCode getPackageDynamicCodeInfo(String packageName) {
return mPackageDynamicCodeLoading.getPackageDynamicCodeInfo(packageName);
}
@VisibleForTesting
void writeDclEvent(int uid, String message) {
EventLog.writeEvent(SNET_TAG, DCL_SUBTAG, uid, message);
}
void record(int loaderUserId, String dexPath,
String owningPackageName, String loadingPackageName) {
if (mPackageDynamicCodeLoading.record(owningPackageName, dexPath,
PackageDynamicCodeLoading.FILE_TYPE_DEX, loaderUserId,
loadingPackageName)) {
mPackageDynamicCodeLoading.maybeWriteAsync();
}
}
void clear() {
mPackageDynamicCodeLoading.clear();
}
void removePackage(String packageName) {
if (mPackageDynamicCodeLoading.removePackage(packageName)) {
mPackageDynamicCodeLoading.maybeWriteAsync();
}
}
void removeUserPackage(String packageName, int userId) {
if (mPackageDynamicCodeLoading.removeUserPackage(packageName, userId)) {
mPackageDynamicCodeLoading.maybeWriteAsync();
}
}
void readAndSync(Map<String, Set<Integer>> packageToUsersMap) {
mPackageDynamicCodeLoading.read();
mPackageDynamicCodeLoading.syncData(packageToUsersMap);
}
void writeNow() {
mPackageDynamicCodeLoading.writeNow();
}
}

59
services/core/java/com/android/server/pm/dex/DexManager.java
View File

@@ -19,7 +19,6 @@ package com.android.server.pm.dex;
import static com.android.server.pm.InstructionSets.getAppDexInstructionSets;
import static com.android.server.pm.dex.PackageDexUsage.DexUseInfo;
import static com.android.server.pm.dex.PackageDexUsage.PackageUseInfo;
import static com.android.server.pm.dex.PackageDynamicCodeLoading.PackageDynamicCode;
import android.content.ContentResolver;
import android.content.Context;
@@ -90,18 +89,17 @@ public class DexManager {
// encode and save the dex usage data.
private final PackageDexUsage mPackageDexUsage;
// PackageDynamicCodeLoading handles recording of dynamic code loading -
// which is similar to PackageDexUsage but records a different aspect of the data.
// DexLogger handles recording of dynamic code loading - which is similar to PackageDexUsage
// but records a different aspect of the data.
// (It additionally includes DEX files loaded with unsupported class loaders, and doesn't
// record class loaders or ISAs.)
private final PackageDynamicCodeLoading mPackageDynamicCodeLoading;
private final DexLogger mDexLogger;
private final IPackageManager mPackageManager;
private final PackageDexOptimizer mPackageDexOptimizer;
private final Object mInstallLock;
@GuardedBy("mInstallLock")
private final Installer mInstaller;
private final Listener mListener;
// Possible outcomes of a dex search.
private static int DEX_SEARCH_NOT_FOUND = 0; // dex file not found
@@ -122,26 +120,20 @@ public class DexManager {
*/
private final static PackageUseInfo DEFAULT_USE_INFO = new PackageUseInfo();
public interface Listener {
/**
* Invoked just before the secondary dex file {@code dexPath} for the specified application
* is reconciled.
*/
void onReconcileSecondaryDexFile(ApplicationInfo appInfo, DexUseInfo dexUseInfo,
String dexPath, int storageFlags);
}
public DexManager(Context context, IPackageManager pms, PackageDexOptimizer pdo,
Installer installer, Object installLock, Listener listener) {
Installer installer, Object installLock) {
mContext = context;
mPackageCodeLocationsCache = new HashMap<>();
mPackageDexUsage = new PackageDexUsage();
mPackageDynamicCodeLoading = new PackageDynamicCodeLoading();
mPackageManager = pms;
mPackageDexOptimizer = pdo;
mInstaller = installer;
mInstallLock = installLock;
mListener = listener;
mDexLogger = new DexLogger(pms, installer, installLock);
}
public DexLogger getDexLogger() {
return mDexLogger;
}
public void systemReady() {
@@ -243,11 +235,8 @@ public class DexManager {
continue;
}
if (mPackageDynamicCodeLoading.record(searchResult.mOwningPackageName, dexPath,
PackageDynamicCodeLoading.FILE_TYPE_DEX, loaderUserId,
loadingAppInfo.packageName)) {
mPackageDynamicCodeLoading.maybeWriteAsync();
}
mDexLogger.record(loaderUserId, dexPath, searchResult.mOwningPackageName,
loadingAppInfo.packageName);
if (classLoaderContexts != null) {
@@ -284,7 +273,7 @@ public class DexManager {
loadInternal(existingPackages);
} catch (Exception e) {
mPackageDexUsage.clear();
mPackageDynamicCodeLoading.clear();
mDexLogger.clear();
Slog.w(TAG, "Exception while loading. Starting with a fresh state.", e);
}
}
@@ -335,16 +324,12 @@ public class DexManager {
if (mPackageDexUsage.removePackage(packageName)) {
mPackageDexUsage.maybeWriteAsync();
}
if (mPackageDynamicCodeLoading.removePackage(packageName)) {
mPackageDynamicCodeLoading.maybeWriteAsync();
}
mDexLogger.removePackage(packageName);
} else {
if (mPackageDexUsage.removeUserPackage(packageName, userId)) {
mPackageDexUsage.maybeWriteAsync();
}
if (mPackageDynamicCodeLoading.removeUserPackage(packageName, userId)) {
mPackageDynamicCodeLoading.maybeWriteAsync();
}
mDexLogger.removeUserPackage(packageName, userId);
}
}
@@ -423,10 +408,9 @@ public class DexManager {
}
try {
mPackageDynamicCodeLoading.read();
mPackageDynamicCodeLoading.syncData(packageToUsersMap);
mDexLogger.readAndSync(packageToUsersMap);
} catch (Exception e) {
mPackageDynamicCodeLoading.clear();
mDexLogger.clear();
Slog.w(TAG, "Exception while loading package dynamic code usage. "
+ "Starting with a fresh state.", e);
}
@@ -460,11 +444,6 @@ public class DexManager {
return mPackageDexUsage.getPackageUseInfo(packageName) != null;
}
@VisibleForTesting
/*package*/ PackageDynamicCode getPackageDynamicCodeInfo(String packageName) {
return mPackageDynamicCodeLoading.getPackageDynamicCodeInfo(packageName);
}
/**
* Perform dexopt on with the given {@code options} on the secondary dex files.
* @return true if all secondary dex files were processed successfully (compiled or skipped
@@ -574,10 +553,6 @@ public class DexManager {
continue;
}
if (mListener != null) {
mListener.onReconcileSecondaryDexFile(info, dexUseInfo, dexPath, flags);
}
boolean dexStillExists = true;
synchronized(mInstallLock) {
try {
@@ -721,7 +696,7 @@ public class DexManager {
*/
public void writePackageDexUsageNow() {
mPackageDexUsage.writeNow();
mPackageDynamicCodeLoading.writeNow();
mDexLogger.writeNow();
}
private void registerSettingObserver() {

13
services/java/com/android/server/SystemServer.java
View File

@@ -109,6 +109,7 @@ import com.android.server.os.DeviceIdentifiersPolicyService;
import com.android.server.os.SchedulingPolicyService;
import com.android.server.pm.BackgroundDexOptService;
import com.android.server.pm.CrossProfileAppsService;
import com.android.server.pm.DynamicCodeLoggingService;
import com.android.server.pm.Installer;
import com.android.server.pm.LauncherAppsService;
import com.android.server.pm.OtaDexoptService;
@@ -1666,6 +1667,18 @@ public final class SystemServer {
}
traceEnd();
if (!isWatch) {
// We don't run this on watches as there are no plans to use the data logged
// on watch devices.
traceBeginAndSlog("StartDynamicCodeLoggingService");
try {
DynamicCodeLoggingService.schedule(context);
} catch (Throwable e) {
reportWtf("starting DynamicCodeLoggingService", e);
}
traceEnd();
}
if (!isWatch) {
traceBeginAndSlog("StartPruneInstantAppsJobService");
try {

215
services/tests/servicestests/src/com/android/server/pm/dex/DexLoggerTests.java
View File

@@ -16,14 +16,20 @@
package com.android.server.pm.dex;
import static com.android.server.pm.dex.PackageDexUsage.DexUseInfo;
import static com.android.server.pm.dex.PackageDynamicCodeLoading.FILE_TYPE_DEX;
import static com.google.common.truth.Truth.assertThat;
import static org.mockito.Mockito.atMost;
import static org.mockito.Mockito.doReturn;
import static org.mockito.Mockito.doThrow;
import static org.mockito.Mockito.reset;
import static org.mockito.Mockito.verify;
import static org.mockito.Mockito.verifyZeroInteractions;
import android.content.pm.ApplicationInfo;
import android.content.pm.IPackageManager;
import android.content.pm.PackageInfo;
import android.os.storage.StorageManager;
import androidx.test.filters.SmallTest;
@@ -43,13 +49,12 @@ import org.mockito.Mock;
import org.mockito.junit.MockitoJUnit;
import org.mockito.junit.MockitoRule;
import org.mockito.quality.Strictness;
import java.util.Arrays;
import org.mockito.stubbing.Stubber;
@RunWith(AndroidJUnit4.class)
@SmallTest
public class DexLoggerTests {
private static final String PACKAGE_NAME = "package.name";
private static final String OWNING_PACKAGE_NAME = "package.name";
private static final String VOLUME_UUID = "volUuid";
private static final String DEX_PATH = "/bar/foo.jar";
private static final int STORAGE_FLAGS = StorageManager.FLAG_STORAGE_DE;
@@ -66,6 +71,7 @@ public class DexLoggerTests {
};
private static final String CONTENT_HASH =
"0102030405060708090A0B0C0D0E0F101112131415161718191A1B1C1D1E1F20";
private static final byte[] EMPTY_BYTES = {};
@Rule public MockitoRule mockito = MockitoJUnit.rule().strictness(Strictness.STRICT_STUBS);
@@ -73,92 +79,191 @@ public class DexLoggerTests {
@Mock Installer mInstaller;
private final Object mInstallLock = new Object();
private DexManager.Listener mListener;
private PackageDynamicCodeLoading mPackageDynamicCodeLoading;
private DexLogger mDexLogger;
private final ListMultimap<Integer, String> mMessagesForUid = ArrayListMultimap.create();
private boolean mWriteTriggered = false;
private static final String EXPECTED_MESSAGE_WITH_CONTENT_HASH =
DEX_FILENAME_HASH + " " + CONTENT_HASH;
@Before
public void setup() {
public void setup() throws Exception {
// Disable actually attempting to do file writes.
mPackageDynamicCodeLoading = new PackageDynamicCodeLoading() {
@Override
void maybeWriteAsync() {
mWriteTriggered = true;
}
@Override
protected void writeNow(Void data) {
throw new AssertionError("These tests should never call this method.");
}
};
// For test purposes capture log messages as well as sending to the event log.
mListener = new DexLogger(mPM, mInstaller, mInstallLock) {
@Override
mDexLogger = new DexLogger(mPM, mInstaller, mInstallLock, mPackageDynamicCodeLoading) {
@Override
void writeDclEvent(int uid, String message) {
super.writeDclEvent(uid, message);
mMessagesForUid.put(uid, message);
}
};
// Make the owning package exist in our mock PackageManager.
ApplicationInfo appInfo = new ApplicationInfo();
appInfo.deviceProtectedDataDir = "/bar";
appInfo.uid = OWNER_UID;
appInfo.volumeUuid = VOLUME_UUID;
PackageInfo packageInfo = new PackageInfo();
packageInfo.applicationInfo = appInfo;
doReturn(packageInfo).when(mPM)
.getPackageInfo(OWNING_PACKAGE_NAME, /*flags*/ 0, OWNER_USER_ID);
}
@Test
public void testSingleAppWithFileHash() throws Exception {
doReturn(CONTENT_HASH_BYTES).when(mInstaller).hashSecondaryDexFile(
DEX_PATH, PACKAGE_NAME, OWNER_UID, VOLUME_UUID, STORAGE_FLAGS);
public void testOneLoader_ownFile_withFileHash() throws Exception {
whenFileIsHashed(DEX_PATH, doReturn(CONTENT_HASH_BYTES));
runOnReconcile();
recordLoad(OWNING_PACKAGE_NAME, DEX_PATH);
mDexLogger.logDynamicCodeLoading(OWNING_PACKAGE_NAME);
assertThat(mMessagesForUid.keySet()).containsExactly(OWNER_UID);
String expectedMessage = DEX_FILENAME_HASH + " " + CONTENT_HASH;
assertThat(mMessagesForUid).containsEntry(OWNER_UID, expectedMessage);
assertThat(mMessagesForUid.keys()).containsExactly(OWNER_UID);
assertThat(mMessagesForUid).containsEntry(OWNER_UID, EXPECTED_MESSAGE_WITH_CONTENT_HASH);
assertThat(mWriteTriggered).isFalse();
assertThat(mDexLogger.getAllPackagesWithDynamicCodeLoading())
.containsExactly(OWNING_PACKAGE_NAME);
}
@Test
public void testSingleAppNoFileHash() throws Exception {
doReturn(new byte[] { }).when(mInstaller).hashSecondaryDexFile(
DEX_PATH, PACKAGE_NAME, OWNER_UID, VOLUME_UUID, STORAGE_FLAGS);
public void testOneLoader_ownFile_noFileHash() throws Exception {
whenFileIsHashed(DEX_PATH, doReturn(EMPTY_BYTES));
runOnReconcile();
recordLoad(OWNING_PACKAGE_NAME, DEX_PATH);
mDexLogger.logDynamicCodeLoading(OWNING_PACKAGE_NAME);
assertThat(mMessagesForUid.keySet()).containsExactly(OWNER_UID);
assertThat(mMessagesForUid.keys()).containsExactly(OWNER_UID);
assertThat(mMessagesForUid).containsEntry(OWNER_UID, DEX_FILENAME_HASH);
// File should be removed from the DCL list, since we can't hash it.
assertThat(mWriteTriggered).isTrue();
assertThat(mDexLogger.getAllPackagesWithDynamicCodeLoading()).isEmpty();
}
@Test
public void testSingleAppHashFails() throws Exception {
doThrow(new InstallerException("Testing failure")).when(mInstaller).hashSecondaryDexFile(
DEX_PATH, PACKAGE_NAME, OWNER_UID, VOLUME_UUID, STORAGE_FLAGS);
public void testOneLoader_ownFile_hashingFails() throws Exception {
whenFileIsHashed(DEX_PATH, doThrow(new InstallerException("Intentional failure for test")));
runOnReconcile();
recordLoad(OWNING_PACKAGE_NAME, DEX_PATH);
mDexLogger.logDynamicCodeLoading(OWNING_PACKAGE_NAME);
assertThat(mMessagesForUid.keys()).containsExactly(OWNER_UID);
assertThat(mMessagesForUid).containsEntry(OWNER_UID, DEX_FILENAME_HASH);
// File should be removed from the DCL list, since we can't hash it.
assertThat(mWriteTriggered).isTrue();
assertThat(mDexLogger.getAllPackagesWithDynamicCodeLoading()).isEmpty();
}
@Test
public void testOneLoader_ownFile_unknownPath() {
recordLoad(OWNING_PACKAGE_NAME, "other/path");
mDexLogger.logDynamicCodeLoading(OWNING_PACKAGE_NAME);
assertThat(mMessagesForUid).isEmpty();
assertThat(mWriteTriggered).isTrue();
assertThat(mDexLogger.getAllPackagesWithDynamicCodeLoading()).isEmpty();
}
@Test
public void testOtherApps() throws Exception {
doReturn(CONTENT_HASH_BYTES).when(mInstaller).hashSecondaryDexFile(
DEX_PATH, PACKAGE_NAME, OWNER_UID, VOLUME_UUID, STORAGE_FLAGS);
public void testOneLoader_differentOwner() throws Exception {
whenFileIsHashed(DEX_PATH, doReturn(CONTENT_HASH_BYTES));
setPackageUid("other.package.name", 1001);
// Simulate three packages from two different UIDs
String packageName1 = "other1.package.name";
String packageName2 = "other2.package.name";
String packageName3 = "other3.package.name";
int uid1 = 1001;
int uid2 = 1002;
recordLoad("other.package.name", DEX_PATH);
mDexLogger.logDynamicCodeLoading(OWNING_PACKAGE_NAME);
doReturn(uid1).when(mPM).getPackageUid(packageName1, 0, OWNER_USER_ID);
doReturn(uid2).when(mPM).getPackageUid(packageName2, 0, OWNER_USER_ID);
doReturn(uid1).when(mPM).getPackageUid(packageName3, 0, OWNER_USER_ID);
runOnReconcile(packageName1, packageName2, packageName3);
assertThat(mMessagesForUid.keySet()).containsExactly(OWNER_UID, uid1, uid2);
String expectedMessage = DEX_FILENAME_HASH + " " + CONTENT_HASH;
assertThat(mMessagesForUid).containsEntry(OWNER_UID, expectedMessage);
assertThat(mMessagesForUid).containsEntry(uid1, expectedMessage);
assertThat(mMessagesForUid).containsEntry(uid2, expectedMessage);
assertThat(mMessagesForUid.keys()).containsExactly(1001);
assertThat(mMessagesForUid).containsEntry(1001, EXPECTED_MESSAGE_WITH_CONTENT_HASH);
assertThat(mWriteTriggered).isFalse();
}
private void runOnReconcile(String... otherPackageNames) {
ApplicationInfo appInfo = new ApplicationInfo();
appInfo.packageName = PACKAGE_NAME;
appInfo.volumeUuid = VOLUME_UUID;
appInfo.uid = OWNER_UID;
@Test
public void testOneLoader_differentOwner_uninstalled() throws Exception {
whenFileIsHashed(DEX_PATH, doReturn(CONTENT_HASH_BYTES));
setPackageUid("other.package.name", -1);
boolean isUsedByOtherApps = otherPackageNames.length > 0;
DexUseInfo dexUseInfo = new DexUseInfo(
isUsedByOtherApps, OWNER_USER_ID, /* classLoaderContext */ null, /* loaderIsa */ null);
dexUseInfo.getLoadingPackages().addAll(Arrays.asList(otherPackageNames));
recordLoad("other.package.name", DEX_PATH);
mDexLogger.logDynamicCodeLoading(OWNING_PACKAGE_NAME);
mListener.onReconcileSecondaryDexFile(appInfo, dexUseInfo, DEX_PATH, STORAGE_FLAGS);
assertThat(mMessagesForUid).isEmpty();
assertThat(mWriteTriggered).isFalse();
}
@Test
public void testMultipleLoadersAndFiles() throws Exception {
String otherDexPath = "/bar/nosuchdir/foo.jar";
whenFileIsHashed(DEX_PATH, doReturn(CONTENT_HASH_BYTES));
whenFileIsHashed(otherDexPath, doReturn(EMPTY_BYTES));
setPackageUid("other.package.name1", 1001);
setPackageUid("other.package.name2", 1002);
recordLoad("other.package.name1", DEX_PATH);
recordLoad("other.package.name1", otherDexPath);
recordLoad("other.package.name2", DEX_PATH);
recordLoad(OWNING_PACKAGE_NAME, DEX_PATH);
mDexLogger.logDynamicCodeLoading(OWNING_PACKAGE_NAME);
assertThat(mMessagesForUid.keys()).containsExactly(1001, 1001, 1002, OWNER_UID);
assertThat(mMessagesForUid).containsEntry(1001, EXPECTED_MESSAGE_WITH_CONTENT_HASH);
assertThat(mMessagesForUid).containsEntry(1001, DEX_FILENAME_HASH);
assertThat(mMessagesForUid).containsEntry(1002, EXPECTED_MESSAGE_WITH_CONTENT_HASH);
assertThat(mMessagesForUid).containsEntry(OWNER_UID, EXPECTED_MESSAGE_WITH_CONTENT_HASH);
assertThat(mWriteTriggered).isTrue();
assertThat(mDexLogger.getAllPackagesWithDynamicCodeLoading())
.containsExactly(OWNING_PACKAGE_NAME);
// Check the DexLogger caching is working
verify(mPM, atMost(1)).getPackageInfo(OWNING_PACKAGE_NAME, /*flags*/ 0, OWNER_USER_ID);
}
@Test
public void testUnknownOwner() {
reset(mPM);
recordLoad(OWNING_PACKAGE_NAME, DEX_PATH);
mDexLogger.logDynamicCodeLoading("other.package.name");
assertThat(mMessagesForUid).isEmpty();
assertThat(mWriteTriggered).isFalse();
verifyZeroInteractions(mPM);
}
@Test
public void testUninstalledPackage() {
reset(mPM);
recordLoad(OWNING_PACKAGE_NAME, DEX_PATH);
mDexLogger.logDynamicCodeLoading(OWNING_PACKAGE_NAME);
assertThat(mMessagesForUid).isEmpty();
assertThat(mWriteTriggered).isTrue();
assertThat(mDexLogger.getAllPackagesWithDynamicCodeLoading()).isEmpty();
}
private void setPackageUid(String packageName, int uid) throws Exception {
doReturn(uid).when(mPM).getPackageUid(packageName, /*flags*/ 0, OWNER_USER_ID);
}
private void whenFileIsHashed(String dexPath, Stubber stubber) throws Exception {
stubber.when(mInstaller).hashSecondaryDexFile(
dexPath, OWNING_PACKAGE_NAME, OWNER_UID, VOLUME_UUID, STORAGE_FLAGS);
}
private void recordLoad(String loadingPackageName, String dexPath) {
mPackageDynamicCodeLoading.record(
OWNING_PACKAGE_NAME, dexPath, FILE_TYPE_DEX, OWNER_USER_ID, loadingPackageName);
}
}

44
services/tests/servicestests/src/com/android/server/pm/dex/DexManagerTests.java
View File

@@ -27,12 +27,6 @@ import static org.junit.Assert.assertNotEquals;
import static org.junit.Assert.assertNotNull;
import static org.junit.Assert.assertNull;
import static org.junit.Assert.assertTrue;
import static org.mockito.ArgumentMatchers.any;
import static org.mockito.ArgumentMatchers.anyInt;
import static org.mockito.ArgumentMatchers.anyString;
import static org.mockito.Mockito.times;
import static org.mockito.Mockito.verify;
import static org.mockito.Mockito.when;
import android.content.pm.ApplicationInfo;
import android.content.pm.IPackageManager;
@@ -78,7 +72,6 @@ public class DexManagerTests {
@Mock Installer mInstaller;
@Mock IPackageManager mPM;
private final Object mInstallLock = new Object();
@Mock DexManager.Listener mListener;
private DexManager mDexManager;
@@ -114,9 +107,8 @@ public class DexManagerTests {
mBarUser0DelegateLastClassLoader = new TestData(bar, isa, mUser0,
DELEGATE_LAST_CLASS_LOADER_NAME);
mDexManager = new DexManager(
/*Context*/ null, mPM, /*PackageDexOptimizer*/ null, mInstaller, mInstallLock,
mListener);
mDexManager = new DexManager(/*Context*/ null, mPM, /*PackageDexOptimizer*/ null,
mInstaller, mInstallLock);
// Foo and Bar are available to user0.
// Only Bar is available to user1;
@@ -415,9 +407,10 @@ public class DexManagerTests {
String frameworkDex = "/system/framework/com.android.location.provider.jar";
// Load a dex file from framework.
notifyDexLoad(mFooUser0, Arrays.asList(frameworkDex), mUser0);
// The dex file should not be recognized as a package.
assertFalse(mDexManager.hasInfoOnPackage(frameworkDex));
assertNull(mDexManager.getPackageDynamicCodeInfo(frameworkDex));
// The dex file should not be recognized as owned by the package.
assertFalse(mDexManager.hasInfoOnPackage(mFooUser0.getPackageName()));
assertNull(getPackageDynamicCodeInfo(mFooUser0));
}
@Test
@@ -510,21 +503,6 @@ public class DexManagerTests {
assertHasDclInfo(mBarUser0, mBarUser0, secondaries);
}
@Test
public void testReconcileSecondaryDexFiles_invokesListener() throws Exception {
List<String> fooSecondaries = mFooUser0.getSecondaryDexPathsFromProtectedDirs();
notifyDexLoad(mFooUser0, fooSecondaries, mUser0);
when(mPM.getPackageInfo(mFooUser0.getPackageName(), 0, 0))
.thenReturn(mFooUser0.mPackageInfo);
mDexManager.reconcileSecondaryDexFiles(mFooUser0.getPackageName());
verify(mListener, times(fooSecondaries.size()))
.onReconcileSecondaryDexFile(any(ApplicationInfo.class),
any(DexUseInfo.class), anyString(), anyInt());
}
private void assertSecondaryUse(TestData testData, PackageUseInfo pui,
List<String> secondaries, boolean isUsedByOtherApps, int ownerUserId,
String[] expectedContexts) {
@@ -585,6 +563,10 @@ public class DexManagerTests {
return pui;
}
private PackageDynamicCode getPackageDynamicCodeInfo(TestData testData) {
return mDexManager.getDexLogger().getPackageDynamicCodeInfo(testData.getPackageName());
}
private void assertNoUseInfo(TestData testData) {
assertFalse(mDexManager.hasInfoOnPackage(testData.getPackageName()));
}
@@ -600,11 +582,11 @@ public class DexManagerTests {
}
private void assertNoDclInfo(TestData testData) {
assertNull(mDexManager.getPackageDynamicCodeInfo(testData.getPackageName()));
assertNull(getPackageDynamicCodeInfo(testData));
}
private void assertNoDclInfo(TestData testData, int userId) {
PackageDynamicCode info = mDexManager.getPackageDynamicCodeInfo(testData.getPackageName());
PackageDynamicCode info = getPackageDynamicCodeInfo(testData);
if (info == null) {
return;
}
@@ -615,7 +597,7 @@ public class DexManagerTests {
}
private void assertHasDclInfo(TestData owner, TestData loader, List<String> paths) {
PackageDynamicCode info = mDexManager.getPackageDynamicCodeInfo(owner.getPackageName());
PackageDynamicCode info = getPackageDynamicCodeInfo(owner);
assertNotNull("No DCL data for owner " + owner.getPackageName(), info);
for (String path : paths) {
DynamicCodeFile fileInfo = info.mFileUsageMap.get(path);

186
tests/DexLoggerIntegrationTests/src/com/android/server/pm/dex/DexLoggerIntegrationTests.java
View File

@@ -18,20 +18,23 @@ package com.android.server.pm.dex;
import static com.google.common.truth.Truth.assertThat;
import android.app.UiAutomation;
import android.content.Context;
import android.os.ParcelFileDescriptor;
import android.os.SystemClock;
import android.support.test.InstrumentationRegistry;
import android.support.test.filters.LargeTest;
import android.util.EventLog;
import dalvik.system.DexClassLoader;
import org.junit.After;
import org.junit.AfterClass;
import org.junit.Before;
import org.junit.BeforeClass;
import org.junit.Test;
import org.junit.runner.RunWith;
import org.junit.runners.JUnit4;
import java.io.ByteArrayOutputStream;
import java.io.File;
import java.io.FileOutputStream;
import java.io.InputStream;
@@ -40,6 +43,7 @@ import java.security.MessageDigest;
import java.util.ArrayList;
import java.util.Formatter;
import java.util.List;
import java.util.concurrent.TimeUnit;
/**
* Integration tests for {@link com.android.server.pm.dex.DexLogger}.
@@ -47,10 +51,10 @@ import java.util.List;
* The setup for the test dynamically loads code in a jar extracted
* from our assets (a secondary dex file).
*
* We then use adb to trigger secondary dex file reconcilation (and
* wait for it to complete). As a side-effect of this DexLogger should
* be notified of the file and should log the hash of the file's name
* and content. We verify that this message appears in the event log.
* We then use shell commands to trigger dynamic code logging (and wait
* for it to complete). This causes DexLogger to log the hash of the
* file's name and content. We verify that this message appears in
* the event log.
*
* Run with "atest DexLoggerIntegrationTests".
*/
@@ -58,29 +62,89 @@ import java.util.List;
@RunWith(JUnit4.class)
public final class DexLoggerIntegrationTests {
private static final String PACKAGE_NAME = "com.android.frameworks.dexloggertest";
// Event log tag used for SNET related events
private static final int SNET_TAG = 0x534e4554;
// Subtag used to distinguish dynamic code loading events
private static final String DCL_SUBTAG = "dcl";
// Obtained via "echo -n copied.jar | sha256sum"
private static final String EXPECTED_NAME_HASH =
"1B6C71DB26F36582867432CCA12FB6A517470C9F9AABE9198DD4C5C030D6DC0C";
// All the tags we care about
private static final int[] TAG_LIST = new int[] { SNET_TAG };
private static String expectedContentHash;
// This is {@code DynamicCodeLoggingService#JOB_ID}
private static final int DYNAMIC_CODE_LOGGING_JOB_ID = 2030028;
private static Context sContext;
private static int sMyUid;
@BeforeClass
public static void setUpAll() throws Exception {
Context context = InstrumentationRegistry.getTargetContext();
public static void setUpAll() {
sContext = InstrumentationRegistry.getTargetContext();
sMyUid = android.os.Process.myUid();
}
@Before
public void primeEventLog() {
// Force a round trip to logd to make sure everything is up to date.
// Without this the first test passes and others don't - we don't see new events in the
// log. The exact reason is unclear.
EventLog.writeEvent(SNET_TAG, "Dummy event");
}
@Test
public void testDexLoggerGeneratesEvents() throws Exception {
File privateCopyFile = fileForJar("copied.jar");
// Obtained via "echo -n copied.jar | sha256sum"
String expectedNameHash =
"1B6C71DB26F36582867432CCA12FB6A517470C9F9AABE9198DD4C5C030D6DC0C";
String expectedContentHash = copyAndHashJar(privateCopyFile);
// Feed the jar to a class loader and make sure it contains what we expect.
ClassLoader parentClassLoader = sContext.getClass().getClassLoader();
ClassLoader loader =
new DexClassLoader(privateCopyFile.toString(), null, null, parentClassLoader);
loader.loadClass("com.android.dcl.Simple");
// And make sure we log events about it
long previousEventNanos = mostRecentEventTimeNanos();
runDexLogger();
assertDclLoggedSince(previousEventNanos, expectedNameHash, expectedContentHash);
}
@Test
public void testDexLoggerGeneratesEvents_unknownClassLoader() throws Exception {
File privateCopyFile = fileForJar("copied2.jar");
String expectedNameHash =
"202158B6A3169D78F1722487205A6B036B3F2F5653FDCFB4E74710611AC7EB93";
String expectedContentHash = copyAndHashJar(privateCopyFile);
// This time make sure an unknown class loader is an ancestor of the class loader we use.
ClassLoader knownClassLoader = sContext.getClass().getClassLoader();
ClassLoader unknownClassLoader = new UnknownClassLoader(knownClassLoader);
ClassLoader loader =
new DexClassLoader(privateCopyFile.toString(), null, null, unknownClassLoader);
loader.loadClass("com.android.dcl.Simple");
// And make sure we log events about it
long previousEventNanos = mostRecentEventTimeNanos();
runDexLogger();
assertDclLoggedSince(previousEventNanos, expectedNameHash, expectedContentHash);
}
private static File fileForJar(String name) {
return new File(sContext.getDir("jars", Context.MODE_PRIVATE), name);
}
private static String copyAndHashJar(File copyTo) throws Exception {
MessageDigest hasher = MessageDigest.getInstance("SHA-256");
// Copy the jar from our Java resources to a private data directory
File privateCopy = new File(context.getDir("jars", Context.MODE_PRIVATE), "copied.jar");
Class<?> thisClass = DexLoggerIntegrationTests.class;
try (InputStream input = thisClass.getResourceAsStream("/javalib.jar");
OutputStream output = new FileOutputStream(privateCopy)) {
OutputStream output = new FileOutputStream(copyTo)) {
byte[] buffer = new byte[1024];
while (true) {
int numRead = input.read(buffer);
@@ -92,42 +156,63 @@ public final class DexLoggerIntegrationTests {
}
}
// Remember the SHA-256 of the file content to check that it is the same as
// the value we see logged.
// Compute the SHA-256 of the file content so we can check that it is the same as the value
// we see logged.
Formatter formatter = new Formatter();
for (byte b : hasher.digest()) {
formatter.format("%02X", b);
}
expectedContentHash = formatter.toString();
// Feed the jar to a class loader and make sure it contains what we expect.
ClassLoader loader =
new DexClassLoader(
privateCopy.toString(), null, null, context.getClass().getClassLoader());
loader.loadClass("com.android.dcl.Simple");
return formatter.toString();
}
@Test
public void testDexLoggerReconcileGeneratesEvents() throws Exception {
int[] tagList = new int[] { SNET_TAG };
private static long mostRecentEventTimeNanos() throws Exception {
List<EventLog.Event> events = new ArrayList<>();
// There may already be events in the event log - figure out the most recent one
EventLog.readEvents(tagList, events);
long previousEventNanos =
events.isEmpty() ? 0 : events.get(events.size() - 1).getTimeNanos();
events.clear();
EventLog.readEvents(TAG_LIST, events);
return events.isEmpty() ? 0 : events.get(events.size() - 1).getTimeNanos();
}
Process process = Runtime.getRuntime().exec(
"cmd package reconcile-secondary-dex-files " + PACKAGE_NAME);
int exitCode = process.waitFor();
assertThat(exitCode).isEqualTo(0);
private static void runDexLogger() throws Exception {
// This forces {@code DynamicCodeLoggingService} to start now.
runCommand("cmd jobscheduler run -f android " + DYNAMIC_CODE_LOGGING_JOB_ID);
// Wait for the job to have run.
long startTime = SystemClock.elapsedRealtime();
while (true) {
String response = runCommand(
"cmd jobscheduler get-job-state android " + DYNAMIC_CODE_LOGGING_JOB_ID);
if (!response.contains("pending") && !response.contains("active")) {
break;
}
if (SystemClock.elapsedRealtime() - startTime > TimeUnit.SECONDS.toMillis(10)) {
throw new AssertionError("Job has not completed: " + response);
}
SystemClock.sleep(100);
}
}
int myUid = android.os.Process.myUid();
String expectedMessage = EXPECTED_NAME_HASH + " " + expectedContentHash;
private static String runCommand(String command) throws Exception {
ByteArrayOutputStream response = new ByteArrayOutputStream();
byte[] buffer = new byte[1000];
UiAutomation ui = InstrumentationRegistry.getInstrumentation().getUiAutomation();
ParcelFileDescriptor fd = ui.executeShellCommand(command);
try (InputStream input = new ParcelFileDescriptor.AutoCloseInputStream(fd)) {
while (true) {
int count = input.read(buffer);
if (count == -1) {
break;
}
response.write(buffer, 0, count);
}
}
return response.toString("UTF-8");
}
EventLog.readEvents(tagList, events);
boolean found = false;
private static void assertDclLoggedSince(long previousEventNanos, String expectedNameHash,
String expectedContentHash) throws Exception {
List<EventLog.Event> events = new ArrayList<>();
EventLog.readEvents(TAG_LIST, events);
int found = 0;
for (EventLog.Event event : events) {
if (event.getTimeNanos() <= previousEventNanos) {
continue;
@@ -140,15 +225,28 @@ public final class DexLoggerIntegrationTests {
continue;
}
int uid = (int) data[1];
if (uid != myUid) {
if (uid != sMyUid) {
continue;
}
String message = (String) data[2];
assertThat(message).isEqualTo(expectedMessage);
found = true;
if (!message.startsWith(expectedNameHash)) {
continue;
}
assertThat(message).endsWith(expectedContentHash);
++found;
}
assertThat(found).isTrue();
assertThat(found).isEqualTo(1);
}
/**
* A class loader that does nothing useful, but importantly doesn't extend BaseDexClassLoader.
*/
private static class UnknownClassLoader extends ClassLoader {
UnknownClassLoader(ClassLoader parent) {
super(parent);
}
}
}