Add hooks for IsolatedCompilation metrics am: 81c96f303f am: 6d95870511

Original change: https://android-review.googlesource.com/c/platform/packages/modules/Virtualization/+/2059967

Change-Id: I6d1c1a97b299460c25cb702c2d5a954b781906ca
Signed-off-by: Automerger Merge Worker <android-build-automerger-merge-worker@system.gserviceaccount.com>
diff --git a/compos/composd/aidl/android/system/composd/ICompilationTaskCallback.aidl b/compos/composd/aidl/android/system/composd/ICompilationTaskCallback.aidl
index b334d8b..569bba5 100644
--- a/compos/composd/aidl/android/system/composd/ICompilationTaskCallback.aidl
+++ b/compos/composd/aidl/android/system/composd/ICompilationTaskCallback.aidl
@@ -20,6 +20,13 @@
  * requested compilation task completes.
  */
 oneway interface ICompilationTaskCallback {
+    enum FailureReason {
+        /** We failed to successfully start the VM and run compilation in it. */
+        CompilationFailed,
+        /** We ran compilation in the VM, but it reported a problem. */
+        UnexpectedCompilationResult,
+    }
+
     /**
      * Called if a compilation task has ended successfully, generating all the required artifacts.
      */
@@ -28,5 +35,5 @@
     /**
      * Called if a compilation task has ended unsuccessfully.
      */
-    void onFailure();
+    void onFailure(FailureReason reason, String message);
 }
diff --git a/compos/composd/src/odrefresh_task.rs b/compos/composd/src/odrefresh_task.rs
index 9dec1c1..e06e5fe 100644
--- a/compos/composd/src/odrefresh_task.rs
+++ b/compos/composd/src/odrefresh_task.rs
@@ -19,7 +19,8 @@
 use crate::fd_server_helper::FdServerConfig;
 use crate::instance_starter::CompOsInstance;
 use android_system_composd::aidl::android::system::composd::{
-    ICompilationTask::ICompilationTask, ICompilationTaskCallback::ICompilationTaskCallback,
+    ICompilationTask::ICompilationTask,
+    ICompilationTaskCallback::{FailureReason::FailureReason, ICompilationTaskCallback},
 };
 use android_system_composd::binder::{Interface, Result as BinderResult, Strong};
 use anyhow::{Context, Result};
@@ -99,12 +100,15 @@
                         task.callback.onSuccess()
                     }
                     Ok(exit_code) => {
-                        error!("Unexpected odrefresh result: {:?}", exit_code);
-                        task.callback.onFailure()
+                        let message = format!("Unexpected odrefresh result: {:?}", exit_code);
+                        error!("{}", message);
+                        task.callback
+                            .onFailure(FailureReason::UnexpectedCompilationResult, &message)
                     }
                     Err(e) => {
-                        error!("Running odrefresh failed: {:?}", e);
-                        task.callback.onFailure()
+                        let message = format!("Running odrefresh failed: {:?}", e);
+                        error!("{}", message);
+                        task.callback.onFailure(FailureReason::CompilationFailed, &message)
                     }
                 };
                 if let Err(e) = result {
diff --git a/compos/composd_cmd/composd_cmd.rs b/compos/composd_cmd/composd_cmd.rs
index 9f535d5..6afd711 100644
--- a/compos/composd_cmd/composd_cmd.rs
+++ b/compos/composd_cmd/composd_cmd.rs
@@ -19,7 +19,9 @@
 use android_system_composd::{
     aidl::android::system::composd::{
         ICompilationTask::ICompilationTask,
-        ICompilationTaskCallback::{BnCompilationTaskCallback, ICompilationTaskCallback},
+        ICompilationTaskCallback::{
+            BnCompilationTaskCallback, FailureReason::FailureReason, ICompilationTaskCallback,
+        },
         IIsolatedCompilationService::ApexSource::ApexSource,
         IIsolatedCompilationService::IIsolatedCompilationService,
     },
@@ -68,10 +70,10 @@
     completed: Condvar,
 }
 
-#[derive(Copy, Clone)]
 enum Outcome {
     Succeeded,
-    Failed,
+    Failed(FailureReason, String),
+    TaskDied,
 }
 
 impl Interface for Callback {}
@@ -82,8 +84,8 @@
         Ok(())
     }
 
-    fn onFailure(&self) -> BinderResult<()> {
-        self.0.set_outcome(Outcome::Failed);
+    fn onFailure(&self, reason: FailureReason, message: &str) -> BinderResult<()> {
+        self.0.set_outcome(Outcome::Failed(reason, message.to_owned()));
         Ok(())
     }
 }
@@ -97,14 +99,14 @@
     }
 
     fn wait(&self, duration: Duration) -> Result<Outcome> {
-        let (outcome, result) = self
+        let (mut outcome, result) = self
             .completed
             .wait_timeout_while(self.mutex.lock().unwrap(), duration, |outcome| outcome.is_none())
             .unwrap();
         if result.timed_out() {
             bail!("Timed out waiting for compilation")
         }
-        Ok(outcome.unwrap())
+        Ok(outcome.take().unwrap())
     }
 }
 
@@ -138,7 +140,7 @@
     let state_clone = state.clone();
     let mut death_recipient = DeathRecipient::new(move || {
         eprintln!("CompilationTask died");
-        state_clone.set_outcome(Outcome::Failed);
+        state_clone.set_outcome(Outcome::TaskDied);
     });
     // Note that dropping death_recipient cancels this, so we can't use a temporary here.
     task.as_binder().link_to_death(&mut death_recipient)?;
@@ -147,7 +149,10 @@
 
     match state.wait(timeouts()?.odrefresh_max_execution_time) {
         Ok(Outcome::Succeeded) => Ok(()),
-        Ok(Outcome::Failed) => bail!("Compilation failed"),
+        Ok(Outcome::TaskDied) => bail!("Compilation task died"),
+        Ok(Outcome::Failed(reason, message)) => {
+            bail!("Compilation failed: {:?}: {}", reason, message)
+        }
         Err(e) => {
             if let Err(e) = task.cancel() {
                 eprintln!("Failed to cancel compilation: {:?}", e);
diff --git a/compos/service/java/com/android/server/compos/IsolatedCompilationJobService.java b/compos/service/java/com/android/server/compos/IsolatedCompilationJobService.java
index 75f5334..f77406d 100644
--- a/compos/service/java/com/android/server/compos/IsolatedCompilationJobService.java
+++ b/compos/service/java/com/android/server/compos/IsolatedCompilationJobService.java
@@ -31,6 +31,9 @@
 import android.system.composd.IIsolatedCompilationService;
 import android.util.Log;
 
+import com.android.server.compos.IsolatedCompilationMetrics.CompilationResult;
+
+import java.util.NoSuchElementException;
 import java.util.concurrent.TimeUnit;
 import java.util.concurrent.atomic.AtomicReference;
 
@@ -73,9 +76,15 @@
                 .setRequiresCharging(true)
                 .setRequiresStorageNotLow(true)
                 .build());
-        if (result != JobScheduler.RESULT_SUCCESS) {
+        if (result == JobScheduler.RESULT_SUCCESS) {
+            IsolatedCompilationMetrics.onCompilationScheduled(
+                    IsolatedCompilationMetrics.SCHEDULING_SUCCESS);
+        } else {
+            IsolatedCompilationMetrics.onCompilationScheduled(
+                    IsolatedCompilationMetrics.SCHEDULING_FAILURE);
             Log.e(TAG, "Failed to schedule staged APEX job");
         }
+
     }
 
     static boolean isStagedApexJobScheduled(JobScheduler scheduler) {
@@ -99,8 +108,13 @@
             return false;  // Already finished
         }
 
+        IsolatedCompilationMetrics metrics = new IsolatedCompilationMetrics();
+        if (jobId != STAGED_APEX_JOB_ID) {
+            metrics.disable();
+        }
+
         CompilationJob newJob = new CompilationJob(IsolatedCompilationJobService.this::onCompletion,
-                params);
+                params, metrics);
         mCurrentJob.set(newJob);
 
         // This can take some time - we need to start up a VM - so we do it on a separate
@@ -113,6 +127,7 @@
                     newJob.start(jobId);
                 } catch (RuntimeException e) {
                     Log.e(TAG, "Starting CompilationJob failed", e);
+                    metrics.onCompilationEnded(IsolatedCompilationMetrics.RESULT_FAILED_TO_START);
                     mCurrentJob.set(null);
                     newJob.stop(); // Just in case it managed to start before failure
                     jobFinished(params, /*wantReschedule=*/ false);
@@ -153,15 +168,17 @@
 
     static class CompilationJob extends ICompilationTaskCallback.Stub
             implements IBinder.DeathRecipient {
+        private final IsolatedCompilationMetrics mMetrics;
         private final AtomicReference<ICompilationTask> mTask = new AtomicReference<>();
         private final CompilationCallback mCallback;
         private final JobParameters mParams;
         private volatile boolean mStopRequested = false;
-        private volatile boolean mCanceled = false;
 
-        CompilationJob(CompilationCallback callback, JobParameters params) {
+        CompilationJob(CompilationCallback callback, JobParameters params,
+                IsolatedCompilationMetrics metrics) {
             mCallback = requireNonNull(callback);
             mParams = params;
+            mMetrics = requireNonNull(metrics);
         }
 
         void start(int jobId) {
@@ -181,6 +198,7 @@
                 } else {
                     composTask = composd.startStagedApexCompile(this);
                 }
+                mMetrics.onCompilationStarted();
                 mTask.set(composTask);
                 composTask.asBinder().linkToDeath(this, 0);
             } catch (RemoteException e) {
@@ -202,10 +220,10 @@
         private void cancelTask() {
             ICompilationTask task = mTask.getAndSet(null);
             if (task != null) {
-                mCanceled = true;
                 Log.i(TAG, "Cancelling task");
                 try {
                     task.cancel();
+                    mMetrics.onCompilationEnded(IsolatedCompilationMetrics.RESULT_JOB_CANCELED);
                 } catch (RuntimeException | RemoteException e) {
                     // If canceling failed we'll assume it means that the task has already failed;
                     // there's nothing else we can do anyway.
@@ -216,23 +234,44 @@
 
         @Override
         public void binderDied() {
-            onFailure();
+            onCompletion(false, IsolatedCompilationMetrics.RESULT_COMPOSD_DIED);
         }
 
         @Override
         public void onSuccess() {
-            onCompletion(true);
+            onCompletion(true, IsolatedCompilationMetrics.RESULT_SUCCESS);
         }
 
         @Override
-        public void onFailure() {
-            onCompletion(false);
+        public void onFailure(byte reason, String message) {
+            int result;
+            switch (reason) {
+                case ICompilationTaskCallback.FailureReason.CompilationFailed:
+                    result = IsolatedCompilationMetrics.RESULT_COMPILATION_FAILED;
+                    break;
+
+                case ICompilationTaskCallback.FailureReason.UnexpectedCompilationResult:
+                    result = IsolatedCompilationMetrics.RESULT_UNEXPECTED_COMPILATION_RESULT;
+                    break;
+
+                default:
+                    result = IsolatedCompilationMetrics.RESULT_UNKNOWN_FAILURE;
+                    break;
+            }
+            Log.w(TAG, "Compilation failed: " + message);
+            onCompletion(false, result);
         }
 
-        private void onCompletion(boolean succeeded) {
-            mTask.set(null);
-            if (!mCanceled) {
+        private void onCompletion(boolean succeeded, @CompilationResult int result) {
+            ICompilationTask task = mTask.getAndSet(null);
+            if (task != null) {
+                mMetrics.onCompilationEnded(result);
                 mCallback.onCompletion(mParams, succeeded);
+                try {
+                    task.asBinder().unlinkToDeath(this, 0);
+                } catch (NoSuchElementException e) {
+                    // Harmless
+                }
             }
         }
     }
diff --git a/compos/service/java/com/android/server/compos/IsolatedCompilationMetrics.java b/compos/service/java/com/android/server/compos/IsolatedCompilationMetrics.java
new file mode 100644
index 0000000..a8fc39d
--- /dev/null
+++ b/compos/service/java/com/android/server/compos/IsolatedCompilationMetrics.java
@@ -0,0 +1,87 @@
+/*
+ * Copyright 2022 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.compos;
+
+import android.annotation.IntDef;
+import android.os.SystemClock;
+import android.util.Log;
+
+import java.lang.annotation.Retention;
+import java.lang.annotation.RetentionPolicy;
+
+/**
+ * A class that handles reporting metrics relating to Isolated Compilation to statsd.
+ *
+ * @hide
+ */
+class IsolatedCompilationMetrics {
+    private static final String TAG = IsolatedCompilationMetrics.class.getName();
+
+    // TODO(b/218525257): Move the definition of these enums to atoms.proto
+    @Retention(RetentionPolicy.SOURCE)
+    @IntDef({RESULT_SUCCESS, RESULT_UNKNOWN_FAILURE, RESULT_FAILED_TO_START, RESULT_JOB_CANCELED,
+            RESULT_COMPILATION_FAILED, RESULT_UNEXPECTED_COMPILATION_RESULT, RESULT_COMPOSD_DIED})
+    public @interface CompilationResult {}
+
+    public static final int RESULT_SUCCESS = 0;
+    public static final int RESULT_UNKNOWN_FAILURE = 1;
+    public static final int RESULT_FAILED_TO_START = 2;
+    public static final int RESULT_JOB_CANCELED = 3;
+    public static final int RESULT_COMPILATION_FAILED = 4;
+    public static final int RESULT_UNEXPECTED_COMPILATION_RESULT = 5;
+    public static final int RESULT_COMPOSD_DIED = 6;
+
+    @Retention(RetentionPolicy.SOURCE)
+    @IntDef({SCHEDULING_SUCCESS, SCHEDULING_FAILURE})
+    public @interface ScheduleJobResult {}
+
+    public static final int SCHEDULING_SUCCESS = 0;
+    public static final int SCHEDULING_FAILURE = 1;
+
+    private long mCompilationStartTimeMs = 0;
+    private boolean mEnabled = true; // TODO(b/205296305) Remove this
+
+    public static void onCompilationScheduled(@ScheduleJobResult int result) {
+        // TODO(b/218525257): write to ArtStatsLog instead of logcat
+        // ArtStatsLog.write(ArtStatsLog.ISOLATED_COMPILATION_SCHEDULED, result);
+        Log.i(TAG, "ISOLATED_COMPILATION_SCHEDULED: " + result);
+    }
+
+    public void disable() {
+        mEnabled = false;
+    }
+
+    public void onCompilationStarted() {
+        if (mEnabled) {
+            mCompilationStartTimeMs = SystemClock.elapsedRealtime();
+        }
+    }
+
+    public void onCompilationEnded(@CompilationResult int result) {
+        if (!mEnabled) {
+            return;
+        }
+
+        long compilationTime = mCompilationStartTimeMs == 0 ? -1
+                : SystemClock.elapsedRealtime() - mCompilationStartTimeMs;
+        mCompilationStartTimeMs = 0;
+
+        // TODO(b/218525257): write to ArtStatsLog instead of logcat
+        // ArtStatsLog.write(ArtStatsLog.ISOLATED_COMPILATION_ENDED, result, compilationTime);
+        Log.i(TAG, "ISOLATED_COMPILATION_ENDED: " + result + ", " + compilationTime);
+    }
+}