Skip to content

Commit

Permalink
Update telemetry for Pre-reboot Dexopt.
Browse files Browse the repository at this point in the history
- Distinguish system requirement check failures from unexpected
  failures.
- Count packages that have Pre-reboot Dexopt artifacts before the
  reboot.
- Distinguish OTA updates from Mainline updates.

Example proto message:

status: STATUS_FINISHED
optimized_package_count: 21
failed_package_count: 0
skipped_package_count: 91
total_package_count: 112
job_scheduled_timestamp_millis: 1717512730432
job_runs {
  job_started_timestamp_millis: 1717512784302
  job_ended_timestamp_millis: 1717512815902
}
packages_with_artifacts_before_reboot_count: 21
job_type: JOB_TYPE_MAINLINE

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: 21
          failed_package_count: 0
          skipped_package_count: 91
          total_package_count: 112
          job_duration_millis: 31600
          job_latency_millis: 53870
          packages_with_artifacts_after_reboot_count: 21
          packages_with_artifacts_usable_after_reboot_count: 21
          job_run_count: 1
          packages_with_artifacts_before_reboot_count: 21
          job_type: JOB_TYPE_MAINLINE
        }
      }
      elapsed_timestamp_nanos: 72785286422
    }
  }
}
is_active: true
estimated_data_bytes: 160

Bug: 336239721
Bug: 311377497
Test: atest ArtServiceTests
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: I06e9dd6ee59792a45fcc1b1291b79b1c7b1bc9bf
  • Loading branch information
jiakaiz-g committed Jun 6, 2024
1 parent 701fccd commit 91021cd
Show file tree
Hide file tree
Showing 7 changed files with 182 additions and 52 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -160,7 +160,7 @@ public synchronized CompletableFuture<Void> onUpdateReadyStartNow(@Nullable Stri
if (!isEnabled()) {
return null;
}
mInjector.getStatsReporter().recordJobScheduled(false /* isAsync */);
mInjector.getStatsReporter().recordJobScheduled(false /* isAsync */, isOtaUpdate());
return startLocked(null /* onJobFinishedLocked */);
}

Expand Down Expand Up @@ -223,7 +223,7 @@ public synchronized void waitForRunningJob() {

if (result == JobScheduler.RESULT_SUCCESS) {
AsLog.i("Pre-reboot Dexopt Job scheduled");
mInjector.getStatsReporter().recordJobScheduled(true /* isAsync */);
mInjector.getStatsReporter().recordJobScheduled(true /* isAsync */, isOtaUpdate());
return ArtFlags.SCHEDULE_SUCCESS;
} else {
AsLog.i("Failed to schedule Pre-reboot Dexopt Job");
Expand Down Expand Up @@ -405,6 +405,11 @@ private void markHasStarted(boolean value) {
ArtJni.setProperty("dalvik.vm.pre-reboot.has-started", String.valueOf(value));
}

@GuardedBy("this")
private boolean isOtaUpdate() {
return mOtaSlot != null;
}

/**
* Injector pattern for testing purpose.
*
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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.prereboot.PreRebootManagerInterface.SystemRequirementException;
import static com.android.server.art.proto.PreRebootStats.Status;

import android.annotation.NonNull;
Expand Down Expand Up @@ -89,20 +90,31 @@ public boolean run(@Nullable String otaSlot, boolean mapSnapshotsForOta,
@NonNull CancellationSignal cancellationSignal) {
var statsReporter = new PreRebootStatsReporter();
boolean success = false;
boolean systemRequirementCheckFailed = false;
try {
statsReporter.recordJobStarted();
if (!setUp(otaSlot, mapSnapshotsForOta)) {
return false;
}
setUp(otaSlot, mapSnapshotsForOta);
runFromChroot(cancellationSignal);
success = true;
return true;
} catch (RemoteException e) {
Utils.logArtdException(e);
} catch (ServiceSpecificException e) {
AsLog.e("Failed to set up chroot", e);
} catch (SystemRequirementException e) {
systemRequirementCheckFailed = true;
AsLog.e("System requirement check failed", e);
} catch (ReflectiveOperationException e) {
AsLog.wtf("Failed to run Pre-reboot Dexopt", e);
Throwable cause = e.getCause();
if (cause != null
&& cause.getClass().getName().equals(
SystemRequirementException.class.getName())) {
// For future use only. Can't happen for now.
systemRequirementCheckFailed = true;
AsLog.e("System requirement check failed in chroot", cause);
} else {
AsLog.wtf("Failed to run Pre-reboot Dexopt", e);
}
} catch (IOException | ErrnoException e) {
AsLog.e("Failed to run Pre-reboot Dexopt", e);
} finally {
Expand All @@ -115,7 +127,7 @@ public boolean run(@Nullable String otaSlot, boolean mapSnapshotsForOta,
} catch (ServiceSpecificException | IOException e) {
AsLog.e("Failed to tear down chroot", e);
} finally {
statsReporter.recordJobEnded(success);
statsReporter.recordJobEnded(success, systemRequirementCheckFailed);
}
}
return false;
Expand All @@ -124,15 +136,15 @@ public boolean run(@Nullable String otaSlot, boolean mapSnapshotsForOta,
public void test() {
boolean teardownAttempted = false;
try {
if (!setUp(null /* otaSlot */, false /* mapSnapshotsForOta */)) {
throw new AssertionError("System requirement check failed");
}
setUp(null /* otaSlot */, false /* mapSnapshotsForOta */);
// Ideally, we should try dexopting some packages here. However, it's not trivial to
// pass a package list into chroot. Besides, we need to generate boot images even if we
// dexopt only one package, and that can easily make the test fail the CTS quality
// requirement on test duration (<30s).
teardownAttempted = true;
tearDown();
} catch (SystemRequirementException e) {
throw new AssertionError("System requirement check failed", e);
} catch (RemoteException | IOException e) {
throw new AssertionError("Unexpected exception", e);
} finally {
Expand All @@ -146,14 +158,13 @@ public void test() {
}
}

private boolean setUp(@Nullable String otaSlot, boolean mapSnapshotsForOta)
throws RemoteException {
private void setUp(@Nullable String otaSlot, boolean mapSnapshotsForOta)
throws RemoteException, SystemRequirementException {
mInjector.getDexoptChrootSetup().setUp(otaSlot, mapSnapshotsForOta);
if (!mInjector.getArtd().checkPreRebootSystemRequirements(CHROOT_DIR)) {
return false;
throw new SystemRequirementException("See logs for details");
}
mInjector.getDexoptChrootSetup().init();
return true;
}

private void tearDown() throws RemoteException, IOException {
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -73,8 +73,8 @@ public void run(@NonNull ArtModuleServiceManager artModuleServiceManager,

var progressSession = new PreRebootStatsReporter().new ProgressSession();

// Contains three values: skipped, performed, failed.
List<Integer> values = new ArrayList(List.of(0, 0, 0));
// Contains four values: skipped, performed, failed, has pre-reboot artifacts.
List<Integer> values = new ArrayList(List.of(0, 0, 0, 0));

// Record every progress change right away, in case the job is interrupted by a reboot.
Consumer<OperationProgress> progressCallback = progress -> {
Expand All @@ -101,9 +101,12 @@ public void run(@NonNull ArtModuleServiceManager artModuleServiceManager,
default:
throw new IllegalStateException("Unknown status: " + result.getStatus());
}
if (hasExistingArtifacts(result) || result.hasUpdatedArtifacts()) {
values.set(3, values.get(3) + 1);
}

progressSession.recordProgress(
values.get(0), values.get(1), values.get(2), progress.getTotal());
progressSession.recordProgress(values.get(0), values.get(1), values.get(2),
progress.getTotal(), values.get(3));
};

try (var snapshot = packageManagerLocal.withFilteredSnapshot()) {
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -42,5 +42,11 @@
@RequiresApi(Build.VERSION_CODES.VANILLA_ICE_CREAM)
public interface PreRebootManagerInterface {
void run(@NonNull ArtModuleServiceManager artModuleServiceManager, @NonNull Context context,
@NonNull CancellationSignal cancellationSignal);
@NonNull CancellationSignal cancellationSignal) throws SystemRequirementException;

public static class SystemRequirementException extends Exception {
public SystemRequirementException(@NonNull String message) {
super(message);
}
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -17,6 +17,7 @@
package com.android.server.art.prereboot;

import static com.android.server.art.proto.PreRebootStats.JobRun;
import static com.android.server.art.proto.PreRebootStats.JobType;
import static com.android.server.art.proto.PreRebootStats.Status;

import android.annotation.NonNull;
Expand Down Expand Up @@ -78,9 +79,10 @@ public PreRebootStatsReporter(@NonNull Injector injector) {
mInjector = injector;
}

public void recordJobScheduled(boolean isAsync) {
public void recordJobScheduled(boolean isAsync, boolean isOtaUpdate) {
PreRebootStats.Builder statsBuilder = PreRebootStats.newBuilder();
statsBuilder.setStatus(Status.STATUS_SCHEDULED);
statsBuilder.setStatus(Status.STATUS_SCHEDULED)
.setJobType(isOtaUpdate ? JobType.JOB_TYPE_OTA : JobType.JOB_TYPE_MAINLINE);
// Omit job_scheduled_timestamp_millis to indicate a synchronous job.
if (isAsync) {
statsBuilder.setJobScheduledTimestampMillis(mInjector.getCurrentTimeMillis());
Expand All @@ -102,15 +104,19 @@ public void recordJobStarted() {
.setSkippedPackageCount(0)
.setOptimizedPackageCount(0)
.setFailedPackageCount(0)
.setTotalPackageCount(0);
.setTotalPackageCount(0)
// Some packages may have artifacts from a previously cancelled job, but we count
// from scratch for simplicity.
.setPackagesWithArtifactsBeforeRebootCount(0);
save(statsBuilder);
}

public class ProgressSession {
private @NonNull PreRebootStats.Builder mStatsBuilder = load();

public void recordProgress(int skippedPackageCount, int optimizedPackageCount,
int failedPackageCount, int totalPackageCount) {
int failedPackageCount, int totalPackageCount,
int packagesWithArtifactsBeforeRebootCount) {
if (mStatsBuilder.getStatus() == Status.STATUS_UNKNOWN) {
// Failed to load, the error is already logged.
return;
Expand All @@ -119,12 +125,14 @@ public void recordProgress(int skippedPackageCount, int optimizedPackageCount,
mStatsBuilder.setSkippedPackageCount(skippedPackageCount)
.setOptimizedPackageCount(optimizedPackageCount)
.setFailedPackageCount(failedPackageCount)
.setTotalPackageCount(totalPackageCount);
.setTotalPackageCount(totalPackageCount)
.setPackagesWithArtifactsBeforeRebootCount(
packagesWithArtifactsBeforeRebootCount);
save(mStatsBuilder);
}
}

public void recordJobEnded(boolean success) {
public void recordJobEnded(boolean success, boolean systemRequirementCheckFailed) {
PreRebootStats.Builder statsBuilder = load();
if (statsBuilder.getStatus() == Status.STATUS_UNKNOWN) {
// Failed to load, the error is already logged.
Expand All @@ -144,6 +152,7 @@ public void recordJobEnded(boolean success) {
// The job is cancelled if it hasn't done package scanning (total package count is 0),
// or it's interrupted in the middle of package processing (package counts don't add up
// to the total).
// TODO(b/336239721): Move this logic to the server.
if (statsBuilder.getTotalPackageCount() > 0
&& (statsBuilder.getOptimizedPackageCount()
+ statsBuilder.getFailedPackageCount()
Expand All @@ -154,7 +163,11 @@ public void recordJobEnded(boolean success) {
status = Status.STATUS_CANCELLED;
}
} else {
status = Status.STATUS_FAILED;
if (systemRequirementCheckFailed) {
status = Status.STATUS_ABORTED_SYSTEM_REQUIREMENTS;
} else {
status = Status.STATUS_FAILED;
}
}

statsBuilder.setStatus(status).setJobRuns(jobRuns.size() - 1, runBuilder);
Expand Down Expand Up @@ -225,7 +238,9 @@ public void report() {
statsBuilder.getOptimizedPackageCount(), statsBuilder.getFailedPackageCount(),
statsBuilder.getSkippedPackageCount(), statsBuilder.getTotalPackageCount(),
jobDurationMs, jobLatencyMs, mPackagesWithArtifacts.size(),
packagesWithArtifactsUsableCount, jobRuns.size());
packagesWithArtifactsUsableCount, jobRuns.size(),
statsBuilder.getPackagesWithArtifactsBeforeRebootCount(),
getJobTypeForStatsd(statsBuilder.getJobType()));
}
}

Expand All @@ -243,11 +258,27 @@ private int getStatusForStatsd(@NonNull Status status) {
return ArtStatsLog.PRE_REBOOT_DEXOPT_JOB_ENDED__STATUS__STATUS_FAILED;
case STATUS_CANCELLED:
return ArtStatsLog.PRE_REBOOT_DEXOPT_JOB_ENDED__STATUS__STATUS_CANCELLED;
case STATUS_ABORTED_SYSTEM_REQUIREMENTS:
return ArtStatsLog
.PRE_REBOOT_DEXOPT_JOB_ENDED__STATUS__STATUS_ABORTED_SYSTEM_REQUIREMENTS;
default:
throw new IllegalStateException("Unknown status: " + status.getNumber());
}
}

private int getJobTypeForStatsd(@NonNull JobType jobType) {
switch (jobType) {
case JOB_TYPE_UNKNOWN:
return ArtStatsLog.PRE_REBOOT_DEXOPT_JOB_ENDED__JOB_TYPE__JOB_TYPE_UNKNOWN;
case JOB_TYPE_OTA:
return ArtStatsLog.PRE_REBOOT_DEXOPT_JOB_ENDED__JOB_TYPE__JOB_TYPE_OTA;
case JOB_TYPE_MAINLINE:
return ArtStatsLog.PRE_REBOOT_DEXOPT_JOB_ENDED__JOB_TYPE__JOB_TYPE_MAINLINE;
default:
throw new IllegalStateException("Unknown job type: " + jobType.getNumber());
}
}

private boolean hasUsablePreRebootArtifacts(@NonNull DexoptStatus status) {
// 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.
Expand Down Expand Up @@ -327,11 +358,13 @@ public void writeStats(int code, int status, int optimizedPackageCount,
int failedPackageCount, int skippedPackageCount, int totalPackageCount,
long jobDurationMillis, long jobLatencyMillis,
int packagesWithArtifactsAfterRebootCount,
int packagesWithArtifactsUsableAfterRebootCount, int jobRunCount) {
int packagesWithArtifactsUsableAfterRebootCount, int jobRunCount,
int packagesWithArtifactsBeforeRebootCount, int jobType) {
ArtStatsLog.write(code, status, optimizedPackageCount, failedPackageCount,
skippedPackageCount, totalPackageCount, jobDurationMillis, jobLatencyMillis,
packagesWithArtifactsAfterRebootCount,
packagesWithArtifactsUsableAfterRebootCount, jobRunCount);
packagesWithArtifactsUsableAfterRebootCount, jobRunCount,
packagesWithArtifactsBeforeRebootCount, jobType);
}
}
}
Loading

0 comments on commit 91021cd

Please sign in to comment.