diff options
author | 2024-05-15 19:44:55 +0100 | |
---|---|---|
committer | 2024-05-23 18:07:55 +0000 | |
commit | b7ab61a7597b58e91f51b91e7c99e306cf8fdabb (patch) | |
tree | 76c278a7ac1d1b01c5770bdc9af7186a23526af2 | |
parent | e32f9f4ac71ea56deff55a87f65ab849f1c093a8 (diff) |
Implement telemetry for Pre-reboot Dexopt.
Pre-reboot Dexopt records stats in a proto before the reboot, and
reports them after reboot, combined with more stats.
Example proto message:
status: STATUS_FINISHED
optimized_package_count: 20
failed_package_count: 0
skipped_package_count: 92
total_package_count: 112
job_scheduled_timestamp_millis: 1715966552854
job_runs {
job_started_timestamp_millis: 1715966561261
job_ended_timestamp_millis: 1715966595124
}
Example reported stats:
metric_id: 1111
event_metrics {
data {
aggregated_atom_info {
atom {
[android.os.statsd.art.prereboot_dexopt_job_ended] {
status: STATUS_FINISHED
optimized_package_count: 20
failed_package_count: 0
skipped_package_count: 92
total_package_count: 112
job_duration_millis: 33863
job_latency_millis: 8407
packages_with_artifacts_after_reboot_count: 20
packages_with_artifacts_usable_after_reboot_count: 20
job_run_count: 1
}
}
elapsed_timestamp_nanos: 79508872408
}
}
}
is_active: true
estimated_data_bytes: 136
Bug: 336239721
Bug: 311377497
Test: -
1. adb root
2. adb shell device_config put runtime enable_pr_dexopt true
3. Install an ART apex.
4. adb shell cat /data/system/pre-reboot-stats.pb | aprotoc --decode=com.android.server.art.proto.PreRebootStats art/libartservice/service/proto/pre_reboot_stats.proto
5. adb shell cmd jobscheduler run android 27873781
6. adb shell cat /data/system/pre-reboot-stats.pb | aprotoc --decode=com.android.server.art.proto.PreRebootStats art/libartservice/service/proto/pre_reboot_stats.proto
7. adb reboot
8. statsd_testdrive 883
Change-Id: I2ca8ad7338f2c6b4c5e9033af3f5ead1e04567d5
15 files changed, 528 insertions, 35 deletions
diff --git a/artd/artd.cc b/artd/artd.cc index d87588bbc9..2619f65cfc 100644 --- a/artd/artd.cc +++ b/artd/artd.cc @@ -1372,9 +1372,9 @@ ScopedAStatus Artd::getProfileSize(const ProfilePath& in_profile, int64_t* _aidl return ScopedAStatus::ok(); } -ScopedAStatus Artd::commitPreRebootStagedFiles( - const std::vector<ArtifactsPath>& in_artifacts, - const std::vector<WritableProfilePath>& in_profiles) { +ScopedAStatus Artd::commitPreRebootStagedFiles(const std::vector<ArtifactsPath>& in_artifacts, + const std::vector<WritableProfilePath>& in_profiles, + bool* _aidl_return) { RETURN_FATAL_IF_PRE_REBOOT(options_); std::vector<std::pair<std::string, std::string>> files_to_move; @@ -1424,6 +1424,7 @@ ScopedAStatus Artd::commitPreRebootStagedFiles( LOG(INFO) << ART_FORMAT("Committed Pre-reboot staged file '{}' to '{}'", src_path, dst_path); } + *_aidl_return = !files_to_move.empty(); return ScopedAStatus::ok(); } diff --git a/artd/artd.h b/artd/artd.h index a926dbc652..d7c9effc6b 100644 --- a/artd/artd.h +++ b/artd/artd.h @@ -225,7 +225,8 @@ class Artd : public aidl::com::android::server::art::BnArtd { ndk::ScopedAStatus commitPreRebootStagedFiles( const std::vector<aidl::com::android::server::art::ArtifactsPath>& in_artifacts, const std::vector<aidl::com::android::server::art::ProfilePath::WritableProfilePath>& - in_profiles) override; + in_profiles, + bool* _aidl_return) override; ndk::ScopedAStatus preRebootInit() override; diff --git a/artd/artd_test.cc b/artd/artd_test.cc index 1c71ab2fbd..9c58dbd366 100644 --- a/artd/artd_test.cc +++ b/artd/artd_test.cc @@ -2509,6 +2509,7 @@ TEST_F(ArtdTest, commitPreRebootStagedFiles) { CreateFile(android_data_ + "/misc/profiles/ref/com.android.bar/primary.prof", "old_prof_2"); + bool aidl_return; ASSERT_STATUS_OK(artd_->commitPreRebootStagedFiles( { // Has all new files. All old files should be replaced. @@ -2529,7 +2530,9 @@ TEST_F(ArtdTest, commitPreRebootStagedFiles) { PrimaryRefProfilePath{.packageName = "com.android.foo", .profileName = "primary"}, // Has no new file. PrimaryRefProfilePath{.packageName = "com.android.bar", .profileName = "primary"}, - })); + }, + &aidl_return)); + EXPECT_TRUE(aidl_return); CheckContent(android_data_ + "/dalvik-cache/arm64/system@app@Foo@Foo.apk@classes.dex", "new_odex_1"); @@ -2565,6 +2568,19 @@ TEST_F(ArtdTest, commitPreRebootStagedFiles) { "/misc/profiles/ref/com.android.foo/primary.prof.staged")); } +TEST_F(ArtdTest, commitPreRebootStagedFilesNoNewFile) { + bool aidl_return; + ASSERT_STATUS_OK(artd_->commitPreRebootStagedFiles( + { + ArtifactsPath{.dexPath = android_data_ + "/app/com.android.foo/base.apk", + .isa = "arm", + .isInDalvikCache = false}, + }, + {}, + &aidl_return)); + EXPECT_FALSE(aidl_return); +} + class ArtdPreRebootTest : public ArtdTest { protected: void SetUp() override { diff --git a/artd/binder/com/android/server/art/IArtd.aidl b/artd/binder/com/android/server/art/IArtd.aidl index 54f55f8460..d49e1aaf59 100644 --- a/artd/binder/com/android/server/art/IArtd.aidl +++ b/artd/binder/com/android/server/art/IArtd.aidl @@ -263,8 +263,10 @@ interface IArtd { * Not supported in Pre-reboot Dexopt mode. * * Throws fatal and non-fatal errors. + * + * @return true if any file has been committed. */ - void commitPreRebootStagedFiles( + boolean commitPreRebootStagedFiles( in List<com.android.server.art.ArtifactsPath> artifacts, in List<com.android.server.art.ProfilePath.WritableProfilePath> profiles); diff --git a/libartservice/service/java/com/android/server/art/ArtManagerLocal.java b/libartservice/service/java/com/android/server/art/ArtManagerLocal.java index e282ffa18a..9303dd9b52 100644 --- a/libartservice/service/java/com/android/server/art/ArtManagerLocal.java +++ b/libartservice/service/java/com/android/server/art/ArtManagerLocal.java @@ -74,6 +74,7 @@ import com.android.server.art.model.DexoptParams; import com.android.server.art.model.DexoptResult; import com.android.server.art.model.DexoptStatus; import com.android.server.art.model.OperationProgress; +import com.android.server.art.prereboot.PreRebootStatsReporter; import com.android.server.pm.PackageManagerLocal; import com.android.server.pm.pkg.AndroidPackage; import com.android.server.pm.pkg.AndroidPackageSplit; @@ -130,6 +131,9 @@ public final class ArtManagerLocal { private boolean mShouldCommitPreRebootStagedFiles = false; + // A temporary object for holding stats while staged files are being committed. + @Nullable private PreRebootStatsReporter mPreRebootStatsReporter = null; + @Deprecated public ArtManagerLocal() { mInjector = new Injector(); @@ -876,6 +880,7 @@ public final class ArtManagerLocal { // to commit files for secondary dex files because they are not decrypted before // then. mShouldCommitPreRebootStagedFiles = true; + mPreRebootStatsReporter = mInjector.createPreRebootStatsReporter(); commitPreRebootStagedFiles(snapshot, false /* forSecondary */); } dexoptPackages(snapshot, bootReason, new CancellationSignal(), progressCallbackExecutor, @@ -903,6 +908,8 @@ public final class ArtManagerLocal { try (var snapshot = mInjector.getPackageManagerLocal().withFilteredSnapshot()) { commitPreRebootStagedFiles(snapshot, true /* forSecondary */); } + mPreRebootStatsReporter.reportAsync(); + mPreRebootStatsReporter = null; } }, new IntentFilter(Intent.ACTION_BOOT_COMPLETED)); } @@ -1132,7 +1139,10 @@ public final class ArtManagerLocal { // ones generated by background dexopt, committing the artifacts while failing // to commit the profile can potentially cause a permanent performance // regression. - mInjector.getArtd().commitPreRebootStagedFiles(artifacts, profiles); + if (mInjector.getArtd().commitPreRebootStagedFiles(artifacts, profiles)) { + mPreRebootStatsReporter.recordPackageWithArtifacts( + pkgState.getPackageName()); + } } catch (ServiceSpecificException e) { AsLog.e("Failed to commit Pre-reboot staged files for package '" + pkgState.getPackageName() + "'", @@ -1644,5 +1654,11 @@ public final class ArtManagerLocal { public DexMetadataHelper getDexMetadataHelper() { return new DexMetadataHelper(); } + + @RequiresApi(Build.VERSION_CODES.VANILLA_ICE_CREAM) + @NonNull + public PreRebootStatsReporter createPreRebootStatsReporter() { + return new PreRebootStatsReporter(); + } } } diff --git a/libartservice/service/java/com/android/server/art/DexoptHelper.java b/libartservice/service/java/com/android/server/art/DexoptHelper.java index 76edfd503f..261e886a4c 100644 --- a/libartservice/service/java/com/android/server/art/DexoptHelper.java +++ b/libartservice/service/java/com/android/server/art/DexoptHelper.java @@ -147,15 +147,18 @@ public class DexoptHelper { if (progressCallback != null) { CompletableFuture.runAsync(() -> { - progressCallback.accept( - OperationProgress.create(0 /* current */, futures.size())); + progressCallback.accept(OperationProgress.create( + 0 /* current */, futures.size(), null /* packageDexoptResult */)); }, progressCallbackExecutor); AtomicInteger current = new AtomicInteger(0); for (CompletableFuture<PackageDexoptResult> future : futures) { - future.thenRunAsync(() -> { - progressCallback.accept(OperationProgress.create( - current.incrementAndGet(), futures.size())); - }, progressCallbackExecutor); + future.thenAcceptAsync(result -> { + progressCallback.accept(OperationProgress.create( + current.incrementAndGet(), futures.size(), result)); + }, progressCallbackExecutor).exceptionally(t -> { + AsLog.e("Failed to update progress", t); + return null; + }); } } diff --git a/libartservice/service/java/com/android/server/art/PreRebootDexoptJob.java b/libartservice/service/java/com/android/server/art/PreRebootDexoptJob.java index c867c4c243..e71eb2cf41 100644 --- a/libartservice/service/java/com/android/server/art/PreRebootDexoptJob.java +++ b/libartservice/service/java/com/android/server/art/PreRebootDexoptJob.java @@ -37,6 +37,7 @@ import com.android.internal.annotations.VisibleForTesting; import com.android.server.art.model.ArtFlags; import com.android.server.art.model.ArtServiceJobInterface; import com.android.server.art.prereboot.PreRebootDriver; +import com.android.server.art.prereboot.PreRebootStatsReporter; import java.time.Duration; import java.util.Objects; @@ -68,8 +69,8 @@ public class PreRebootDexoptJob implements ArtServiceJobInterface { @NonNull private final BlockingQueue<Runnable> mWorkQueue = new LinkedBlockingQueue<>(); /** - * Serializes mutations to the global state of Pre-reboot Dexopt, including mounts and staged - * files. + * Serializes mutations to the global state of Pre-reboot Dexopt, including mounts, staged + * files, and stats. */ @NonNull private final ThreadPoolExecutor mSerializedExecutor = @@ -141,6 +142,7 @@ public class PreRebootDexoptJob implements ArtServiceJobInterface { */ public @ScheduleStatus int onUpdateReady(@Nullable String otaSlot) { unschedule(); + mSerializedExecutor.execute(() -> mInjector.getStatsReporter().reset()); updateOtaSlot(otaSlot); return schedule(); } @@ -180,6 +182,7 @@ public class PreRebootDexoptJob implements ArtServiceJobInterface { /* @JobScheduler.Result */ int result = mInjector.getJobScheduler().schedule(info); if (result == JobScheduler.RESULT_SUCCESS) { AsLog.i("Pre-reboot Dexopt Job scheduled"); + mSerializedExecutor.execute(() -> mInjector.getStatsReporter().recordJobScheduled()); return ArtFlags.SCHEDULE_SUCCESS; } else { AsLog.i("Failed to schedule Pre-reboot Dexopt Job"); @@ -212,8 +215,8 @@ public class PreRebootDexoptJob implements ArtServiceJobInterface { mHasStarted = true; mRunningJob = new CompletableFuture().supplyAsync(() -> { try { - // TODO(b/336239721): Consume the result and report metrics. - mInjector.getPreRebootDriver().run(otaSlot, cancellationSignal); + mInjector.getPreRebootDriver().run( + otaSlot, cancellationSignal, mInjector.getStatsReporter()); } catch (RuntimeException e) { AsLog.e("Fatal error", e); } finally { @@ -276,9 +279,11 @@ public class PreRebootDexoptJob implements ArtServiceJobInterface { @VisibleForTesting public static class Injector { @NonNull private final Context mContext; + @NonNull private final PreRebootStatsReporter mStatsReporter; Injector(@NonNull Context context) { mContext = context; + mStatsReporter = new PreRebootStatsReporter(); } @NonNull @@ -290,5 +295,10 @@ public class PreRebootDexoptJob implements ArtServiceJobInterface { public PreRebootDriver getPreRebootDriver() { return new PreRebootDriver(mContext); } + + @NonNull + public PreRebootStatsReporter getStatsReporter() { + return mStatsReporter; + } } } diff --git a/libartservice/service/java/com/android/server/art/model/OperationProgress.java b/libartservice/service/java/com/android/server/art/model/OperationProgress.java index a0a7ddc4fc..90186726ea 100644 --- a/libartservice/service/java/com/android/server/art/model/OperationProgress.java +++ b/libartservice/service/java/com/android/server/art/model/OperationProgress.java @@ -16,14 +16,21 @@ package com.android.server.art.model; +import static com.android.server.art.model.DexoptResult.PackageDexoptResult; + import android.annotation.NonNull; +import android.annotation.Nullable; import android.annotation.SystemApi; import com.android.internal.annotations.Immutable; import com.google.auto.value.AutoValue; -/** @hide */ +/** + * Represents the progress of an operation. Currently, this is only for batch dexopt. + * + * @hide + */ @SystemApi(client = SystemApi.Client.SYSTEM_SERVER) @Immutable @AutoValue @@ -32,8 +39,9 @@ public abstract class OperationProgress { protected OperationProgress() {} /** @hide */ - public static @NonNull OperationProgress create(int current, int total) { - return new AutoValue_OperationProgress(current, total); + public static @NonNull OperationProgress create( + int current, int total, @Nullable PackageDexoptResult packageDexoptResult) { + return new AutoValue_OperationProgress(current, total, packageDexoptResult); } /** The overall progress, in the range of [0, 100]. */ @@ -59,4 +67,12 @@ public abstract class OperationProgress { * @hide */ public abstract int getTotal(); + + /** + * The last package dexopt result, or null if {@link #getCurrent} returns 0. Only applicable if + * this class represents batch dexopt progress. + * + * @hide + */ + public abstract @Nullable PackageDexoptResult getLastPackageDexoptResult(); } diff --git a/libartservice/service/java/com/android/server/art/prereboot/PreRebootDriver.java b/libartservice/service/java/com/android/server/art/prereboot/PreRebootDriver.java index 40c8913f07..ef0b99ac34 100644 --- a/libartservice/service/java/com/android/server/art/prereboot/PreRebootDriver.java +++ b/libartservice/service/java/com/android/server/art/prereboot/PreRebootDriver.java @@ -17,6 +17,7 @@ package com.android.server.art.prereboot; import static com.android.server.art.IDexoptChrootSetup.CHROOT_DIR; +import static com.android.server.art.proto.PreRebootStats.Status; import android.annotation.NonNull; import android.annotation.Nullable; @@ -68,8 +69,10 @@ public class PreRebootDriver { * @param otaSlot The slot that contains the OTA update, "_a" or "_b", or null for a Mainline * update. */ - public boolean run(@Nullable String otaSlot, @NonNull CancellationSignal cancellationSignal) { + public boolean run(@Nullable String otaSlot, @NonNull CancellationSignal cancellationSignal, + @NonNull PreRebootStatsReporter statsReporter) { try { + statsReporter.recordJobStarted(); setUp(otaSlot); runFromChroot(cancellationSignal); return true; @@ -82,6 +85,9 @@ public class PreRebootDriver { } finally { tearDown(); } + // Only report the failed case here. The finished and cancelled cases are reported by + // PreRebootManager. + statsReporter.recordJobEnded(Status.STATUS_FAILED); return false; } diff --git a/libartservice/service/java/com/android/server/art/prereboot/PreRebootManager.java b/libartservice/service/java/com/android/server/art/prereboot/PreRebootManager.java index d6947ba156..cb91dc324b 100644 --- a/libartservice/service/java/com/android/server/art/prereboot/PreRebootManager.java +++ b/libartservice/service/java/com/android/server/art/prereboot/PreRebootManager.java @@ -16,6 +16,9 @@ package com.android.server.art.prereboot; +import static com.android.server.art.model.DexoptResult.PackageDexoptResult; +import static com.android.server.art.proto.PreRebootStats.Status; + import android.annotation.NonNull; import android.content.Context; import android.os.ArtModuleServiceManager; @@ -27,10 +30,22 @@ import androidx.annotation.RequiresApi; import com.android.server.LocalManagerRegistry; import com.android.server.art.ArtManagerLocal; import com.android.server.art.ArtdRefCache; +import com.android.server.art.AsLog; import com.android.server.art.ReasonMapping; +import com.android.server.art.Utils; +import com.android.server.art.model.ArtFlags; +import com.android.server.art.model.DexoptResult; +import com.android.server.art.model.OperationProgress; import com.android.server.pm.PackageManagerLocal; +import java.util.ArrayList; +import java.util.List; +import java.util.Map; import java.util.Objects; +import java.util.concurrent.ExecutorService; +import java.util.concurrent.Executors; +import java.util.concurrent.TimeUnit; +import java.util.function.Consumer; /** * Implementation of {@link PreRebootManagerInterface}. @@ -46,18 +61,69 @@ import java.util.Objects; public class PreRebootManager implements PreRebootManagerInterface { public void run(@NonNull ArtModuleServiceManager artModuleServiceManager, @NonNull Context context, @NonNull CancellationSignal cancellationSignal) { + ExecutorService callbackExecutor = Executors.newSingleThreadExecutor(); try { PreRebootGlobalInjector.init(artModuleServiceManager, context); ArtManagerLocal artManagerLocal = new ArtManagerLocal(context); PackageManagerLocal packageManagerLocal = Objects.requireNonNull( LocalManagerRegistry.getManager(PackageManagerLocal.class)); + + var statsReporter = new PreRebootStatsReporter(); + statsReporter.load(); + + // Contains three values: skipped, performed, failed. + List<Integer> values = new ArrayList(List.of(0, 0, 0)); + + // Record every progress change right away, in case the job is interrupted by a reboot. + Consumer<OperationProgress> progressCallback = progress -> { + PackageDexoptResult result = progress.getLastPackageDexoptResult(); + if (result == null) { + return; + } + switch (result.getStatus()) { + case DexoptResult.DEXOPT_SKIPPED: + values.set(0, values.get(0) + 1); + break; + case DexoptResult.DEXOPT_PERFORMED: + values.set(1, values.get(1) + 1); + break; + case DexoptResult.DEXOPT_FAILED: + values.set(2, values.get(2) + 1); + break; + case DexoptResult.DEXOPT_CANCELLED: + break; + default: + throw new IllegalStateException("Unknown status: " + result.getStatus()); + } + + statsReporter.recordProgress( + values.get(0), values.get(1), values.get(2), progress.getTotal()); + }; + + // Record `STATUS_FINISHED` even if the result is `DEXOPT_FAILED`. This is because + // `DEXOPT_FAILED` means dexopt failed for some packages, while the job is considered + // successful overall. + artManagerLocal.addDexoptDoneCallback(false /* onlyIncludeUpdates */, callbackExecutor, + (result) + -> statsReporter.recordJobEnded( + result.getFinalStatus() == DexoptResult.DEXOPT_CANCELLED + ? Status.STATUS_CANCELLED + : Status.STATUS_FINISHED)); + try (var snapshot = packageManagerLocal.withFilteredSnapshot()) { artManagerLocal.dexoptPackages(snapshot, ReasonMapping.REASON_PRE_REBOOT_DEXOPT, - cancellationSignal, null /* processCallbackExecutor */, - null /* processCallback */); + cancellationSignal, callbackExecutor, + Map.of(ArtFlags.PASS_MAIN, progressCallback)); } } finally { ArtdRefCache.getInstance().reset(); + callbackExecutor.shutdown(); + try { + // Make sure we have no running threads when we tear down. + callbackExecutor.awaitTermination(Integer.MAX_VALUE, TimeUnit.SECONDS); + } catch (InterruptedException e) { + AsLog.wtf("Interrupted", e); + } } } } diff --git a/libartservice/service/java/com/android/server/art/prereboot/PreRebootStatsReporter.java b/libartservice/service/java/com/android/server/art/prereboot/PreRebootStatsReporter.java new file mode 100644 index 0000000000..175b2d3b7e --- /dev/null +++ b/libartservice/service/java/com/android/server/art/prereboot/PreRebootStatsReporter.java @@ -0,0 +1,261 @@ +/* + * Copyright (C) 2024 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.art.prereboot; + +import static com.android.server.art.proto.PreRebootStats.JobRun; +import static com.android.server.art.proto.PreRebootStats.Status; + +import android.annotation.NonNull; +import android.os.Build; + +import androidx.annotation.RequiresApi; + +import com.android.internal.annotations.VisibleForTesting; +import com.android.server.LocalManagerRegistry; +import com.android.server.art.ArtManagerLocal; +import com.android.server.art.ArtStatsLog; +import com.android.server.art.ArtdRefCache; +import com.android.server.art.AsLog; +import com.android.server.art.ReasonMapping; +import com.android.server.art.Utils; +import com.android.server.art.model.DexoptStatus; +import com.android.server.art.proto.PreRebootStats; +import com.android.server.pm.PackageManagerLocal; + +import java.io.File; +import java.io.FileInputStream; +import java.io.FileOutputStream; +import java.io.IOException; +import java.io.InputStream; +import java.io.OutputStream; +import java.nio.file.Files; +import java.nio.file.StandardCopyOption; +import java.util.HashSet; +import java.util.List; +import java.util.Objects; +import java.util.Set; +import java.util.concurrent.CompletableFuture; +import java.util.function.Function; + +/** + * A helper class to report the Pre-reboot Dexopt metrics to StatsD. + * + * This class is not thread-safe. + * + * During Pre-reboot Dexopt, both the old version and the new version of this code is run. The old + * version writes to disk first, and the new version writes to disk later. After reboot, the new + * version loads from disk. + * + * @hide + */ +@RequiresApi(Build.VERSION_CODES.UPSIDE_DOWN_CAKE) +public class PreRebootStatsReporter { + private static final String FILENAME = "/data/system/pre-reboot-stats.pb"; + + @NonNull private final Injector mInjector; + + private @NonNull PreRebootStats.Builder mStatsBuilder = PreRebootStats.newBuilder(); + private @NonNull Set<String> mPackagesWithArtifacts = new HashSet<>(); + + public PreRebootStatsReporter() { + this(new Injector()); + } + + /** @hide */ + @VisibleForTesting + public PreRebootStatsReporter(@NonNull Injector injector) { + mInjector = injector; + } + + public void recordJobScheduled() { + mStatsBuilder.clear(); + mStatsBuilder.setStatus(Status.STATUS_SCHEDULED) + .setJobScheduledTimestampMillis(System.currentTimeMillis()); + save(); + } + + public void recordJobStarted() { + Utils.check(mStatsBuilder.getStatus() != Status.STATUS_UNKNOWN); + + JobRun.Builder runBuilder = + JobRun.newBuilder().setJobStartedTimestampMillis(System.currentTimeMillis()); + mStatsBuilder.setStatus(Status.STATUS_STARTED) + .addJobRuns(runBuilder) + .setSkippedPackageCount(0) + .setOptimizedPackageCount(0) + .setFailedPackageCount(0) + .setTotalPackageCount(0); + save(); + } + + public void recordProgress(int skippedPackageCount, int optimizedPackageCount, + int failedPackageCount, int totalPackageCount) { + mStatsBuilder.setSkippedPackageCount(skippedPackageCount) + .setOptimizedPackageCount(optimizedPackageCount) + .setFailedPackageCount(failedPackageCount) + .setTotalPackageCount(totalPackageCount); + save(); + } + + public void recordJobEnded(Status status) { + Utils.check(status == Status.STATUS_FINISHED || status == Status.STATUS_FAILED + || status == Status.STATUS_CANCELLED); + + List<JobRun> jobRuns = mStatsBuilder.getJobRunsList(); + Utils.check(jobRuns.size() > 0); + JobRun lastRun = jobRuns.get(jobRuns.size() - 1); + Utils.check(lastRun.getJobEndedTimestampMillis() == 0 || status == Status.STATUS_FAILED); + + JobRun.Builder runBuilder = + JobRun.newBuilder(lastRun).setJobEndedTimestampMillis(System.currentTimeMillis()); + mStatsBuilder.setStatus(status).setJobRuns(jobRuns.size() - 1, runBuilder); + save(); + } + + public void recordPackageWithArtifacts(@NonNull String packageName) { + mPackagesWithArtifacts.add(packageName); + } + + public void reportAsync() { + new CompletableFuture().runAsync(this::report).exceptionally(t -> { + AsLog.e("Failed to report stats", t); + return null; + }); + } + + private void report() { + load(); + delete(); + + if (mStatsBuilder.getStatus() == Status.STATUS_UNKNOWN) { + // Job not scheduled, probably because Pre-reboot Dexopt is not enabled. + return; + } + + PackageManagerLocal packageManagerLocal = + Objects.requireNonNull(LocalManagerRegistry.getManager(PackageManagerLocal.class)); + ArtManagerLocal artManagerLocal = + Objects.requireNonNull(LocalManagerRegistry.getManager(ArtManagerLocal.class)); + + // This takes some time (~3ms per package). It probably fine because we are running + // asynchronously. Consider removing this in the future. + int packagesWithArtifactsUsableCount; + try (var snapshot = packageManagerLocal.withFilteredSnapshot(); + var pin = ArtdRefCache.getInstance().new Pin()) { + packagesWithArtifactsUsableCount = + (int) mPackagesWithArtifacts.stream() + .map(packageName + -> artManagerLocal.getDexoptStatus(snapshot, packageName)) + // For simplicity, we consider all artifacts of a package usable if we + // see at least one `REASON_PRE_REBOOT_DEXOPT` because it's not easy to + // know which files are committed. + .filter(status + -> status.getDexContainerFileDexoptStatuses().stream().anyMatch( + fileStatus + -> fileStatus.getCompilationReason().equals( + ReasonMapping.REASON_PRE_REBOOT_DEXOPT))) + .count(); + } + + List<JobRun> jobRuns = mStatsBuilder.getJobRunsList(); + // Only take the duration of the last run because every run starts from scratch. + JobRun lastRun = jobRuns.size() > 0 ? jobRuns.get(jobRuns.size() - 1) : null; + long jobDurationMs = (lastRun != null && lastRun.getJobEndedTimestampMillis() > 0) + ? (lastRun.getJobEndedTimestampMillis() - lastRun.getJobStartedTimestampMillis()) + : -1; + long jobLatencyMs = + (jobRuns.size() > 0 && mStatsBuilder.getJobScheduledTimestampMillis() > 0) + ? (jobRuns.get(0).getJobStartedTimestampMillis() + - mStatsBuilder.getJobScheduledTimestampMillis()) + : -1; + + ArtStatsLog.write(ArtStatsLog.PREREBOOT_DEXOPT_JOB_ENDED, getStatusForStatsd(), + mStatsBuilder.getOptimizedPackageCount(), mStatsBuilder.getFailedPackageCount(), + mStatsBuilder.getSkippedPackageCount(), mStatsBuilder.getTotalPackageCount(), + jobDurationMs, jobLatencyMs, mPackagesWithArtifacts.size(), + packagesWithArtifactsUsableCount, jobRuns.size()); + } + + private int getStatusForStatsd() { + switch (mStatsBuilder.getStatus()) { + case STATUS_UNKNOWN: + return ArtStatsLog.PRE_REBOOT_DEXOPT_JOB_ENDED__STATUS__STATUS_UNKNOWN; + case STATUS_SCHEDULED: + return ArtStatsLog.PRE_REBOOT_DEXOPT_JOB_ENDED__STATUS__STATUS_SCHEDULED; + case STATUS_STARTED: + return ArtStatsLog.PRE_REBOOT_DEXOPT_JOB_ENDED__STATUS__STATUS_STARTED; + case STATUS_FINISHED: + return ArtStatsLog.PRE_REBOOT_DEXOPT_JOB_ENDED__STATUS__STATUS_FINISHED; + case STATUS_FAILED: + return ArtStatsLog.PRE_REBOOT_DEXOPT_JOB_ENDED__STATUS__STATUS_FAILED; + case STATUS_CANCELLED: + return ArtStatsLog.PRE_REBOOT_DEXOPT_JOB_ENDED__STATUS__STATUS_CANCELLED; + default: + throw new IllegalStateException( + "Unknown status: " + mStatsBuilder.getStatus().getNumber()); + } + } + + public void load() { + try (InputStream in = new FileInputStream(mInjector.getFilename())) { + mStatsBuilder.mergeFrom(in); + } catch (IOException e) { + // Nothing else we can do but to start from scratch. + AsLog.e("Failed to load pre-reboot stats", e); + } + } + + private void save() { + var file = new File(mInjector.getFilename()); + File tempFile = null; + try { + tempFile = File.createTempFile(file.getName(), null /* suffix */, file.getParentFile()); + try (OutputStream out = new FileOutputStream(tempFile.getPath())) { + mStatsBuilder.build().writeTo(out); + } + Files.move(tempFile.toPath(), file.toPath(), StandardCopyOption.REPLACE_EXISTING, + StandardCopyOption.ATOMIC_MOVE); + } catch (IOException e) { + AsLog.e("Failed to save pre-reboot stats", e); + } finally { + Utils.deleteIfExistsSafe(tempFile); + } + } + + public void reset() { + mStatsBuilder.clear(); + mPackagesWithArtifacts.clear(); + delete(); + } + + private void delete() { + Utils.deleteIfExistsSafe(new File(mInjector.getFilename())); + } + + /** + * Injector pattern for testing purpose. + * + * @hide + */ + @VisibleForTesting + public static class Injector { + @NonNull + public String getFilename() { + return FILENAME; + } + } +} diff --git a/libartservice/service/javatests/com/android/server/art/ArtManagerLocalTest.java b/libartservice/service/javatests/com/android/server/art/ArtManagerLocalTest.java index 1fd7e4bcfc..44aedca222 100644 --- a/libartservice/service/javatests/com/android/server/art/ArtManagerLocalTest.java +++ b/libartservice/service/javatests/com/android/server/art/ArtManagerLocalTest.java @@ -70,6 +70,7 @@ import com.android.server.art.model.DeleteResult; import com.android.server.art.model.DexoptParams; import com.android.server.art.model.DexoptResult; import com.android.server.art.model.DexoptStatus; +import com.android.server.art.prereboot.PreRebootStatsReporter; import com.android.server.art.proto.DexMetadataConfig; import com.android.server.art.testing.StaticMockitoRule; import com.android.server.art.testing.TestingUtils; @@ -138,6 +139,7 @@ public class ArtManagerLocalTest { @Mock private DexMetadataHelper.Injector mDexMetadataHelperInjector; @Mock private Context mContext; @Mock private PreRebootDexoptJob mPreRebootDexoptJob; + @Mock private PreRebootStatsReporter.Injector mPreRebootStatsReporterInjector; private PackageState mPkgState1; private AndroidPackage mPkg1; private CheckedSecondaryDexInfo mPkg1SecondaryDexInfo1; @@ -182,6 +184,10 @@ public class ArtManagerLocalTest { lenient().when(mInjector.getDexMetadataHelper()).thenReturn(mDexMetadataHelper); lenient().when(mInjector.getContext()).thenReturn(mContext); lenient().when(mInjector.getPreRebootDexoptJob()).thenReturn(mPreRebootDexoptJob); + lenient() + .when(mInjector.createPreRebootStatsReporter()) + .thenAnswer( + invocation -> new PreRebootStatsReporter(mPreRebootStatsReporterInjector)); lenient().when(mArtFileManagerInjector.getArtd()).thenReturn(mArtd); lenient().when(mArtFileManagerInjector.getUserManager()).thenReturn(mUserManager); @@ -284,6 +290,12 @@ public class ArtManagerLocalTest { .when(mContext.registerReceiver(mBroadcastReceiverCaptor.capture(), any())) .thenReturn(mock(Intent.class)); + File tempFile = File.createTempFile("pre-reboot-stats", ".pb"); + tempFile.deleteOnExit(); + lenient() + .when(mPreRebootStatsReporterInjector.getFilename()) + .thenReturn(tempFile.getAbsolutePath()); + mArtManagerLocal = new ArtManagerLocal(mInjector); } diff --git a/libartservice/service/javatests/com/android/server/art/DexoptHelperTest.java b/libartservice/service/javatests/com/android/server/art/DexoptHelperTest.java index 527203b5a3..8fb46b6225 100644 --- a/libartservice/service/javatests/com/android/server/art/DexoptHelperTest.java +++ b/libartservice/service/javatests/com/android/server/art/DexoptHelperTest.java @@ -76,6 +76,7 @@ import java.util.concurrent.TimeUnit; import java.util.concurrent.atomic.AtomicBoolean; import java.util.function.Consumer; import java.util.stream.Collectors; +import java.util.stream.Stream; @SmallTest @RunWith(AndroidJUnit4.class) @@ -670,15 +671,26 @@ public class DexoptHelperTest { progressCallbackExecutor.runAll(); + List<DexContainerFileDexoptResult> fileResults = + Stream.concat(mPrimaryResults.stream(), mSecondaryResults.stream()) + .collect(Collectors.toList()); + InOrder inOrder = inOrder(progressCallback); inOrder.verify(progressCallback) - .accept(eq(OperationProgress.create(0 /* current */, 3 /* total */))); + .accept(eq(OperationProgress.create( + 0 /* current */, 3 /* total */, null /* packageDexoptResult */))); inOrder.verify(progressCallback) - .accept(eq(OperationProgress.create(1 /* current */, 3 /* total */))); + .accept(eq(OperationProgress.create(1 /* current */, 3 /* total */, + PackageDexoptResult.create( + PKG_NAME_FOO, fileResults, null /* packageLevelStatus */)))); inOrder.verify(progressCallback) - .accept(eq(OperationProgress.create(2 /* current */, 3 /* total */))); + .accept(eq(OperationProgress.create(2 /* current */, 3 /* total */, + PackageDexoptResult.create( + PKG_NAME_BAR, fileResults, null /* packageLevelStatus */)))); inOrder.verify(progressCallback) - .accept(eq(OperationProgress.create(3 /* current */, 3 /* total */))); + .accept(eq(OperationProgress.create(3 /* current */, 3 /* total */, + PackageDexoptResult.create( + PKG_NAME_LIBBAZ, fileResults, null /* packageLevelStatus */)))); } private AndroidPackage createPackage(boolean multiSplit) { diff --git a/libartservice/service/javatests/com/android/server/art/PreRebootDexoptJobTest.java b/libartservice/service/javatests/com/android/server/art/PreRebootDexoptJobTest.java index 51d46d6503..924f57aa66 100644 --- a/libartservice/service/javatests/com/android/server/art/PreRebootDexoptJobTest.java +++ b/libartservice/service/javatests/com/android/server/art/PreRebootDexoptJobTest.java @@ -40,6 +40,7 @@ import androidx.test.filters.SmallTest; import com.android.server.art.model.ArtFlags; import com.android.server.art.prereboot.PreRebootDriver; +import com.android.server.art.prereboot.PreRebootStatsReporter; import com.android.server.art.testing.StaticMockitoRule; import org.junit.Before; @@ -50,6 +51,7 @@ import org.mockito.ArgumentCaptor; import org.mockito.Mock; import org.mockito.junit.MockitoJUnitRunner; +import java.io.File; import java.util.concurrent.CompletableFuture; import java.util.concurrent.Future; import java.util.concurrent.Semaphore; @@ -67,6 +69,7 @@ public class PreRebootDexoptJobTest { @Mock private PreRebootDexoptJob.Injector mInjector; @Mock private JobScheduler mJobScheduler; @Mock private PreRebootDriver mPreRebootDriver; + @Mock private PreRebootStatsReporter.Injector mPreRebootStatsReporterInjector; private PreRebootDexoptJob mPreRebootDexoptJob; @Before @@ -85,6 +88,15 @@ public class PreRebootDexoptJobTest { lenient().when(mInjector.getJobScheduler()).thenReturn(mJobScheduler); lenient().when(mInjector.getPreRebootDriver()).thenReturn(mPreRebootDriver); + lenient() + .when(mInjector.getStatsReporter()) + .thenReturn(new PreRebootStatsReporter(mPreRebootStatsReporterInjector)); + + File tempFile = File.createTempFile("pre-reboot-stats", ".pb"); + tempFile.deleteOnExit(); + lenient() + .when(mPreRebootStatsReporterInjector.getFilename()) + .thenReturn(tempFile.getAbsolutePath()); mPreRebootDexoptJob = new PreRebootDexoptJob(mInjector); lenient().when(BackgroundDexoptJobService.getJob(JOB_ID)).thenReturn(mPreRebootDexoptJob); @@ -148,7 +160,7 @@ public class PreRebootDexoptJobTest { @Test public void testStart() { - when(mPreRebootDriver.run(any(), any())).thenReturn(true); + when(mPreRebootDriver.run(any(), any(), any())).thenReturn(true); assertThat(mPreRebootDexoptJob.hasStarted()).isFalse(); Future<Boolean> future = mPreRebootDexoptJob.start(); @@ -159,7 +171,7 @@ public class PreRebootDexoptJobTest { @Test public void testStartAnother() { - when(mPreRebootDriver.run(any(), any())).thenReturn(true); + when(mPreRebootDriver.run(any(), any(), any())).thenReturn(true); Future<Boolean> future1 = mPreRebootDexoptJob.start(); Utils.getFuture(future1); @@ -172,7 +184,7 @@ public class PreRebootDexoptJobTest { public void testCancel() { Semaphore dexoptCancelled = new Semaphore(0); Semaphore jobExited = new Semaphore(0); - when(mPreRebootDriver.run(any(), any())).thenAnswer(invocation -> { + when(mPreRebootDriver.run(any(), any(), any())).thenAnswer(invocation -> { assertThat(dexoptCancelled.tryAcquire(TIMEOUT_SEC, TimeUnit.SECONDS)).isTrue(); var cancellationSignal = invocation.<CancellationSignal>getArgument(1); assertThat(cancellationSignal.isCanceled()).isTrue(); @@ -197,7 +209,7 @@ public class PreRebootDexoptJobTest { mPreRebootDexoptJob.updateOtaSlot("_b"); mPreRebootDexoptJob.updateOtaSlot(null); - when(mPreRebootDriver.run(eq("_b"), any())).thenReturn(true); + when(mPreRebootDriver.run(eq("_b"), any(), any())).thenReturn(true); Utils.getFuture(mPreRebootDexoptJob.start()); } @@ -207,7 +219,7 @@ public class PreRebootDexoptJobTest { mPreRebootDexoptJob.updateOtaSlot(null); mPreRebootDexoptJob.updateOtaSlot("_a"); - when(mPreRebootDriver.run(eq("_a"), any())).thenReturn(true); + when(mPreRebootDriver.run(eq("_a"), any(), any())).thenReturn(true); Utils.getFuture(mPreRebootDexoptJob.start()); } @@ -217,7 +229,7 @@ public class PreRebootDexoptJobTest { mPreRebootDexoptJob.updateOtaSlot(null); mPreRebootDexoptJob.updateOtaSlot(null); - when(mPreRebootDriver.run(isNull(), any())).thenReturn(true); + when(mPreRebootDriver.run(isNull(), any(), any())).thenReturn(true); Utils.getFuture(mPreRebootDexoptJob.start()); } @@ -227,7 +239,7 @@ public class PreRebootDexoptJobTest { mPreRebootDexoptJob.updateOtaSlot("_b"); mPreRebootDexoptJob.updateOtaSlot("_b"); - when(mPreRebootDriver.run(eq("_b"), any())).thenReturn(true); + when(mPreRebootDriver.run(eq("_b"), any(), any())).thenReturn(true); Utils.getFuture(mPreRebootDexoptJob.start()); } @@ -252,7 +264,7 @@ public class PreRebootDexoptJobTest { var globalState = new Semaphore(1); var jobBlocker = new Semaphore(0); - when(mPreRebootDriver.run(any(), any())).thenAnswer(invocation -> { + when(mPreRebootDriver.run(any(), any(), any())).thenAnswer(invocation -> { // Step 2, 5, 8. // Verify that different runs don't mutate the global state concurrently. diff --git a/libartservice/service/proto/pre_reboot_stats.proto b/libartservice/service/proto/pre_reboot_stats.proto new file mode 100644 index 0000000000..4909a5533c --- /dev/null +++ b/libartservice/service/proto/pre_reboot_stats.proto @@ -0,0 +1,59 @@ +/* + * Copyright (C) 2024 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. + */ + +syntax = "proto3"; + +package com.android.server.art.proto; +option java_multiple_files = true; + +// Pre-reboot Dexopt metrics to persist on disk for being reported after reboot. +// This proto is persisted on disk and forward and backward compatibility are considerations. +message PreRebootStats { + // Overall status of the job right before the reboot. + // See `android.os.statsd.art.PreRebootDexoptJobEnded`. + enum Status { + STATUS_UNKNOWN = 0; + STATUS_SCHEDULED = 1; + STATUS_STARTED = 2; + STATUS_FAILED = 3; + STATUS_FINISHED = 4; + STATUS_CANCELLED = 5; + } + optional Status status = 1; + + // Number of packages successfully optimized. + optional int32 optimized_package_count = 2; + // Number of packages failed to optimize. + optional int32 failed_package_count = 3; + // Number of packages skipped. + optional int32 skipped_package_count = 4; + // Total number of packages scanned. + optional int32 total_package_count = 5; + + // When the job is scheduled, in milliseconds. + optional int64 job_scheduled_timestamp_millis = 6; + + // Represents a job run. + message JobRun { + // When the job is started, in milliseconds. + optional int64 job_started_timestamp_millis = 1; + // When the job is ended (failed, finished, or cancelled), in milliseconds. + optional int64 job_ended_timestamp_millis = 2; + } + + // All job runs. The job may be cancelled and rerun multiple times. + repeated JobRun job_runs = 7; +} |