Merge "profcollectd: add interface to wait for ETM after boot."android-t-preview-2android-t-preview-1android-t-beta-3android-s-v2-beta-3android-s-qpr3-beta-1android-t-preview-1android-s-v2-beta-3android-s-qpr3-beta-1

16 files changed, 190 insertions, 32 deletions

diff --git a/profcollectd/Android.bp b/profcollectd/Android.bp
index f1723006..122e4f61 100644
--- a/profcollectd/Android.bp
+++ b/profcollectd/Android.bp
@@ -59,6 +59,7 @@ filegroup {
     name: "profcollectd_aidl",
     srcs: [
         "binder/com/android/server/profcollect/IProfCollectd.aidl",
+        "binder/com/android/server/profcollect/IProviderStatusCallback.aidl",
     ],
     path: "binder",
 }
diff --git a/profcollectd/binder/com/android/server/profcollect/IProfCollectd.aidl b/profcollectd/binder/com/android/server/profcollect/IProfCollectd.aidl
index c8f33a1e..bfc24446 100644
--- a/profcollectd/binder/com/android/server/profcollect/IProfCollectd.aidl
+++ b/profcollectd/binder/com/android/server/profcollect/IProfCollectd.aidl
@@ -16,6 +16,8 @@
 
 package com.android.server.profcollect;
 
+import com.android.server.profcollect.IProviderStatusCallback;
+
 /** {@hide} */
 interface IProfCollectd {
     void schedule();
@@ -24,4 +26,5 @@ interface IProfCollectd {
     void process();
     @utf8InCpp String report();
     @utf8InCpp String get_supported_provider();
+    void registerProviderStatusCallback(IProviderStatusCallback cb);
 }
diff --git a/profcollectd/binder/com/android/server/profcollect/IProviderStatusCallback.aidl b/profcollectd/binder/com/android/server/profcollect/IProviderStatusCallback.aidl
new file mode 100644
index 00000000..b311cf91
--- /dev/null
+++ b/profcollectd/binder/com/android/server/profcollect/IProviderStatusCallback.aidl
@@ -0,0 +1,22 @@
+/*
+ * Copyright (C) 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.profcollect;
+
+/** {@hide} */
+oneway interface IProviderStatusCallback {
+    void onProviderReady();
+}
diff --git a/profcollectd/libprofcollectd/lib.rs b/profcollectd/libprofcollectd/lib.rs
index abc11272..f95132f4 100644
--- a/profcollectd/libprofcollectd/lib.rs
+++ b/profcollectd/libprofcollectd/lib.rs
@@ -30,11 +30,34 @@ use anyhow::{Context, Result};
 use profcollectd_aidl_interface::aidl::com::android::server::profcollect::IProfCollectd::{
     self, BnProfCollectd,
 };
+use profcollectd_aidl_interface::aidl::com::android::server::profcollect::IProviderStatusCallback::{IProviderStatusCallback, BnProviderStatusCallback};
 use profcollectd_aidl_interface::binder::{self, BinderFeatures};
-use service::ProfcollectdBinderService;
+use service::{err_to_binder_status, ProfcollectdBinderService};
+use std::time::{Duration, Instant};
 
 const PROFCOLLECTD_SERVICE_NAME: &str = "profcollectd";
 
+struct ProviderStatusCallback {
+    service_start_time: Instant,
+}
+
+impl binder::Interface for ProviderStatusCallback {}
+
+impl IProviderStatusCallback for ProviderStatusCallback {
+    fn onProviderReady(&self) -> binder::Result<()> {
+        // If we have waited too long for the provider to be ready, then we have passed
+        // boot phase, and no need to collect boot profile.
+        // TODO: should we check boottime instead?
+        const TIMEOUT_TO_COLLECT_BOOT_PROFILE: Duration = Duration::from_secs(3);
+        let elapsed = Instant::now().duration_since(self.service_start_time);
+        if elapsed < TIMEOUT_TO_COLLECT_BOOT_PROFILE {
+            trace_once("boot").map_err(err_to_binder_status)?;
+        }
+        schedule().map_err(err_to_binder_status)?;
+        Ok(())
+    }
+}
+
 /// Initialise profcollectd service.
 /// * `schedule_now` - Immediately schedule collection after service is initialised.
 pub fn init_service(schedule_now: bool) -> Result<()> {
@@ -49,8 +72,11 @@ pub fn init_service(schedule_now: bool) -> Result<()> {
     .context("Failed to register service.")?;
 
     if schedule_now {
-        trace_once("boot")?;
-        schedule()?;
+        let cb = BnProviderStatusCallback::new_binder(
+            ProviderStatusCallback { service_start_time: Instant::now() },
+            BinderFeatures::default(),
+        );
+        get_profcollectd_service()?.registerProviderStatusCallback(&cb)?;
     }
 
     binder::ProcessState::join_thread_pool();
diff --git a/profcollectd/libprofcollectd/logging_trace_provider.rs b/profcollectd/libprofcollectd/logging_trace_provider.rs
index 1325855d..fda4c66a 100644
--- a/profcollectd/libprofcollectd/logging_trace_provider.rs
+++ b/profcollectd/libprofcollectd/logging_trace_provider.rs
@@ -32,6 +32,10 @@ impl TraceProvider for LoggingTraceProvider {
         "logging"
     }
 
+    fn is_ready(&self) -> bool {
+        true
+    }
+
     fn trace(&self, trace_dir: &Path, tag: &str, sampling_period: &Duration) {
         let trace_file = trace_provider::get_path(trace_dir, tag, LOGGING_TRACEFILE_EXTENSION);
 
diff --git a/profcollectd/libprofcollectd/scheduler.rs b/profcollectd/libprofcollectd/scheduler.rs
index 31a495a5..f58c4995 100644
--- a/profcollectd/libprofcollectd/scheduler.rs
+++ b/profcollectd/libprofcollectd/scheduler.rs
@@ -17,11 +17,13 @@
 //! ProfCollect tracing scheduler.
 
 use std::fs;
+use std::mem;
 use std::path::Path;
 use std::sync::mpsc::{sync_channel, SyncSender};
 use std::sync::Arc;
 use std::sync::Mutex;
 use std::thread;
+use std::time::{Duration, Instant};
 
 use crate::config::{Config, PROFILE_OUTPUT_DIR, TRACE_OUTPUT_DIR};
 use crate::trace_provider::{self, TraceProvider};
@@ -33,12 +35,17 @@ pub struct Scheduler {
     termination_ch: Option<SyncSender<()>>,
     /// The preferred trace provider for the system.
     trace_provider: Arc<Mutex<dyn TraceProvider + Send>>,
+    provider_ready_callbacks: Arc<Mutex<Vec<Box<dyn FnOnce() + Send>>>>,
 }
 
 impl Scheduler {
     pub fn new() -> Result<Self> {
         let p = trace_provider::get_trace_provider()?;
-        Ok(Scheduler { termination_ch: None, trace_provider: p })
+        Ok(Scheduler {
+            termination_ch: None,
+            trace_provider: p,
+            provider_ready_callbacks: Arc::new(Mutex::new(Vec::new())),
+        })
     }
 
     fn is_scheduled(&self) -> bool {
@@ -106,6 +113,51 @@ impl Scheduler {
     pub fn get_trace_provider_name(&self) -> &'static str {
         self.trace_provider.lock().unwrap().get_name()
     }
+
+    pub fn is_provider_ready(&self) -> bool {
+        self.trace_provider.lock().unwrap().is_ready()
+    }
+
+    pub fn register_provider_ready_callback(&self, cb: Box<dyn FnOnce() + Send>) {
+        let mut locked_callbacks = self.provider_ready_callbacks.lock().unwrap();
+        locked_callbacks.push(cb);
+        if locked_callbacks.len() == 1 {
+            self.start_thread_waiting_for_provider_ready();
+        }
+    }
+
+    fn start_thread_waiting_for_provider_ready(&self) {
+        let provider = self.trace_provider.clone();
+        let callbacks = self.provider_ready_callbacks.clone();
+
+        thread::spawn(move || {
+            let start_time = Instant::now();
+            loop {
+                let elapsed = Instant::now().duration_since(start_time);
+                if provider.lock().unwrap().is_ready() {
+                    break;
+                }
+                // Decide check period based on how long we have waited:
+                // For the first 10s waiting, check every 100ms (likely to work on EVT devices).
+                // For the first 10m waiting, check every 10s (likely to work on DVT devices).
+                // For others, check every 10m.
+                let sleep_duration = if elapsed < Duration::from_secs(10) {
+                    Duration::from_millis(100)
+                } else if elapsed < Duration::from_secs(60 * 10) {
+                    Duration::from_secs(10)
+                } else {
+                    Duration::from_secs(60 * 10)
+                };
+                thread::sleep(sleep_duration);
+            }
+
+            let mut locked_callbacks = callbacks.lock().unwrap();
+            let v = mem::take(&mut *locked_callbacks);
+            for cb in v {
+                cb();
+            }
+        });
+    }
 }
 
 /// Run if space usage is under limit.
diff --git a/profcollectd/libprofcollectd/service.rs b/profcollectd/libprofcollectd/service.rs
index 0199c105..3f338024 100644
--- a/profcollectd/libprofcollectd/service.rs
+++ b/profcollectd/libprofcollectd/service.rs
@@ -18,8 +18,9 @@
 
 use anyhow::{anyhow, Context, Error, Result};
 use binder::Result as BinderResult;
-use binder::Status;
+use binder::{SpIBinder, Status};
 use profcollectd_aidl_interface::aidl::com::android::server::profcollect::IProfCollectd::IProfCollectd;
+use profcollectd_aidl_interface::aidl::com::android::server::profcollect::IProviderStatusCallback::IProviderStatusCallback;
 use std::ffi::CString;
 use std::fs::{read_dir, read_to_string, remove_file, write};
 use std::str::FromStr;
@@ -32,7 +33,7 @@ use crate::config::{
 use crate::report::{get_report_ts, pack_report};
 use crate::scheduler::Scheduler;
 
-fn err_to_binder_status(msg: Error) -> Status {
+pub fn err_to_binder_status(msg: Error) -> Status {
     let msg = format!("{:#?}", msg);
     let msg = CString::new(msg).expect("Failed to convert to CString");
     Status::new_service_specific_error(1, Some(&msg))
@@ -89,6 +90,30 @@ impl IProfCollectd for ProfcollectdBinderService {
     fn get_supported_provider(&self) -> BinderResult<String> {
         Ok(self.lock().scheduler.get_trace_provider_name().to_string())
     }
+
+    fn registerProviderStatusCallback(
+        &self,
+        cb: &binder::Strong<(dyn IProviderStatusCallback)>,
+    ) -> BinderResult<()> {
+        if self.lock().scheduler.is_provider_ready() {
+            if let Err(e) = cb.onProviderReady() {
+                log::error!("Failed to call ProviderStatusCallback {:?}", e);
+            }
+            return Ok(());
+        }
+
+        let cb_binder: SpIBinder = cb.as_binder();
+        self.lock().scheduler.register_provider_ready_callback(Box::new(move || {
+            if let Ok(cb) = cb_binder.into_interface::<dyn IProviderStatusCallback>() {
+                if let Err(e) = cb.onProviderReady() {
+                    log::error!("Failed to call ProviderStatusCallback {:?}", e)
+                }
+            } else {
+                log::error!("SpIBinder is not a IProviderStatusCallback.");
+            }
+        }));
+        Ok(())
+    }
 }
 
 impl ProfcollectdBinderService {
diff --git a/profcollectd/libprofcollectd/simpleperf_etm_trace_provider.rs b/profcollectd/libprofcollectd/simpleperf_etm_trace_provider.rs
index 14fb7509..f25f5ffc 100644
--- a/profcollectd/libprofcollectd/simpleperf_etm_trace_provider.rs
+++ b/profcollectd/libprofcollectd/simpleperf_etm_trace_provider.rs
@@ -34,6 +34,10 @@ impl TraceProvider for SimpleperfEtmTraceProvider {
         "simpleperf_etm"
     }
 
+    fn is_ready(&self) -> bool {
+        simpleperf_profcollect::has_device_support()
+    }
+
     fn trace(&self, trace_dir: &Path, tag: &str, sampling_period: &Duration) {
         let trace_file = trace_provider::get_path(trace_dir, tag, ETM_TRACEFILE_EXTENSION);
 
@@ -76,6 +80,6 @@ impl TraceProvider for SimpleperfEtmTraceProvider {
 
 impl SimpleperfEtmTraceProvider {
     pub fn supported() -> bool {
-        simpleperf_profcollect::has_support()
+        simpleperf_profcollect::has_driver_support()
     }
 }
diff --git a/profcollectd/libprofcollectd/trace_provider.rs b/profcollectd/libprofcollectd/trace_provider.rs
index 98cd5ec4..13059199 100644
--- a/profcollectd/libprofcollectd/trace_provider.rs
+++ b/profcollectd/libprofcollectd/trace_provider.rs
@@ -29,6 +29,7 @@ use crate::logging_trace_provider::LoggingTraceProvider;
 
 pub trait TraceProvider {
     fn get_name(&self) -> &'static str;
+    fn is_ready(&self) -> bool;
     fn trace(&self, trace_dir: &Path, tag: &str, sampling_period: &Duration);
     fn process(&self, trace_dir: &Path, profile_dir: &Path, binary_filter: &str) -> Result<()>;
 }
diff --git a/simpleperf/ETMRecorder.cpp b/simpleperf/ETMRecorder.cpp
index 7bef4f21..554e8f52 100644
--- a/simpleperf/ETMRecorder.cpp
+++ b/simpleperf/ETMRecorder.cpp
@@ -23,6 +23,7 @@
 #include <memory>
 #include <string>
 
+#include <android-base/expected.h>
 #include <android-base/file.h>
 #include <android-base/logging.h>
 #include <android-base/parseint.h>
@@ -34,6 +35,9 @@
 
 namespace simpleperf {
 
+using android::base::expected;
+using android::base::unexpected;
+
 static constexpr bool ETM_RECORD_TIMESTAMP = false;
 
 static const std::string ETM_DIR = "/sys/bus/event_source/devices/cs_etm/";
@@ -103,32 +107,30 @@ std::unique_ptr<EventType> ETMRecorder::BuildEventType() {
                                      "CoreSight ETM instruction tracing", "arm");
 }
 
-bool ETMRecorder::CheckEtmSupport() {
+bool ETMRecorder::IsETMDriverAvailable() {
+  return IsDir(ETM_DIR);
+}
+
+expected<bool, std::string> ETMRecorder::CheckEtmSupport() {
   if (GetEtmEventType() == -1) {
-    LOG(ERROR) << "etm event type isn't supported on device";
-    return false;
+    return unexpected("etm event type isn't supported on device");
   }
   if (!ReadEtmInfo()) {
-    LOG(ERROR) << "etm devices are not available";
-    return false;
+    return unexpected("etm devices are not available");
   }
   for (const auto& p : etm_info_) {
     if (p.second.GetMajorVersion() < 4) {
-      LOG(ERROR) << "etm device version is less than 4.0";
-      return false;
+      return unexpected("etm device version is less than 4.0");
     }
     if (!p.second.IsContextIDSupported()) {
-      LOG(ERROR) << "etm device doesn't support contextID";
-      return false;
+      return unexpected("etm device doesn't support contextID");
     }
     if (!p.second.IsEnabled()) {
-      LOG(ERROR) << "etm device isn't enabled by the bootloader";
-      return false;
+      return unexpected("etm device isn't enabled by the bootloader");
     }
   }
   if (!FindSinkConfig()) {
-    LOG(ERROR) << "can't find etr device, which moves etm data to memory";
-    return false;
+    return unexpected("can't find etr device, which moves etm data to memory");
   }
   etm_supported_ = true;
   return true;
diff --git a/simpleperf/ETMRecorder.h b/simpleperf/ETMRecorder.h
index 1e33ed80..f304f601 100644
--- a/simpleperf/ETMRecorder.h
+++ b/simpleperf/ETMRecorder.h
@@ -21,6 +21,8 @@
 #include <map>
 #include <memory>
 
+#include <android-base/expected.h>
+
 #include "event_type.h"
 #include "perf_event.h"
 #include "record.h"
@@ -55,7 +57,8 @@ class ETMRecorder {
   // If not found, return -1.
   int GetEtmEventType();
   std::unique_ptr<EventType> BuildEventType();
-  bool CheckEtmSupport();
+  bool IsETMDriverAvailable();
+  android::base::expected<bool, std::string> CheckEtmSupport();
   void SetEtmPerfEventAttr(perf_event_attr* attr);
   AuxTraceInfoRecord CreateAuxTraceInfoRecord();
   size_t GetAddrFilterPairs();
diff --git a/simpleperf/cmd_record_test.cpp b/simpleperf/cmd_record_test.cpp
index f51393f2..ef2c1b68 100644
--- a/simpleperf/cmd_record_test.cpp
+++ b/simpleperf/cmd_record_test.cpp
@@ -917,7 +917,7 @@ TEST(record_cmd, no_cut_samples_option) {
 }
 
 TEST(record_cmd, cs_etm_event) {
-  if (!ETMRecorder::GetInstance().CheckEtmSupport()) {
+  if (!ETMRecorder::GetInstance().CheckEtmSupport().ok()) {
     GTEST_LOG_(INFO) << "Omit this test since etm isn't supported on this device";
     return;
   }
@@ -952,7 +952,7 @@ TEST(record_cmd, cs_etm_event) {
 
 TEST(record_cmd, cs_etm_system_wide) {
   TEST_REQUIRE_ROOT();
-  if (!ETMRecorder::GetInstance().CheckEtmSupport()) {
+  if (!ETMRecorder::GetInstance().CheckEtmSupport().ok()) {
     GTEST_LOG_(INFO) << "Omit this test since etm isn't supported on this device";
     return;
   }
@@ -960,7 +960,7 @@ TEST(record_cmd, cs_etm_system_wide) {
 }
 
 TEST(record_cmd, aux_buffer_size_option) {
-  if (!ETMRecorder::GetInstance().CheckEtmSupport()) {
+  if (!ETMRecorder::GetInstance().CheckEtmSupport().ok()) {
     GTEST_LOG_(INFO) << "Omit this test since etm isn't supported on this device";
     return;
   }
@@ -973,7 +973,7 @@ TEST(record_cmd, aux_buffer_size_option) {
 
 TEST(record_cmd, addr_filter_option) {
   TEST_REQUIRE_HW_COUNTER();
-  if (!ETMRecorder::GetInstance().CheckEtmSupport()) {
+  if (!ETMRecorder::GetInstance().CheckEtmSupport().ok()) {
     GTEST_LOG_(INFO) << "Omit this test since etm isn't supported on this device";
     return;
   }
diff --git a/simpleperf/event_selection_set.cpp b/simpleperf/event_selection_set.cpp
index a6d9a7e0..d5bca318 100644
--- a/simpleperf/event_selection_set.cpp
+++ b/simpleperf/event_selection_set.cpp
@@ -217,7 +217,8 @@ bool EventSelectionSet::BuildAndCheckEventSelection(const std::string& event_nam
   selection->event_attr.precise_ip = event_type->precise_ip;
   if (IsEtmEventType(event_type->event_type.type)) {
     auto& etm_recorder = ETMRecorder::GetInstance();
-    if (!etm_recorder.CheckEtmSupport()) {
+    if (auto result = etm_recorder.CheckEtmSupport(); !result.ok()) {
+      LOG(ERROR) << result.error();
       return false;
     }
     ETMRecorder::GetInstance().SetEtmPerfEventAttr(&selection->event_attr);
diff --git a/simpleperf/include/simpleperf_profcollect.hpp b/simpleperf/include/simpleperf_profcollect.hpp
index f2c48da6..67123e58 100644
--- a/simpleperf/include/simpleperf_profcollect.hpp
+++ b/simpleperf/include/simpleperf_profcollect.hpp
@@ -16,7 +16,8 @@
 
 extern "C" {
 
-bool HasSupport();
+bool HasDriverSupport();
+bool HasDeviceSupport();
 bool Record(const char* event_name, const char* output, float duration);
 bool Inject(const char* traceInput, const char* profileOutput, const char* binary_filter);
 }
diff --git a/simpleperf/profcollect.cpp b/simpleperf/profcollect.cpp
index 3f64abd1..39c04ab7 100644
--- a/simpleperf/profcollect.cpp
+++ b/simpleperf/profcollect.cpp
@@ -24,8 +24,14 @@
 
 using namespace simpleperf;
 
-bool HasSupport() {
-  if (!ETMRecorder::GetInstance().CheckEtmSupport()) {
+bool HasDriverSupport() {
+  return ETMRecorder::GetInstance().IsETMDriverAvailable();
+}
+
+bool HasDeviceSupport() {
+  auto result = ETMRecorder::GetInstance().CheckEtmSupport();
+  if (!result.ok()) {
+    LOG(DEBUG) << result.error();
     return false;
   }
   const EventType* type = FindEventTypeByName("cs-etm", false);
diff --git a/simpleperf/rust/lib.rs b/simpleperf/rust/lib.rs
index c76bf0ea..7d39273e 100644
--- a/simpleperf/rust/lib.rs
+++ b/simpleperf/rust/lib.rs
@@ -25,9 +25,16 @@ fn path_to_cstr(path: &Path) -> CString {
     CString::new(path.to_str().unwrap()).unwrap()
 }
 
-/// Returns whether the system has support for simpleperf etm.
-pub fn has_support() -> bool {
-    unsafe { simpleperf_profcollect_bindgen::HasSupport() }
+/// Returns whether the system has etm driver. ETM driver should be available immediately
+/// after boot.
+pub fn has_driver_support() -> bool {
+    unsafe { simpleperf_profcollect_bindgen::HasDriverSupport() }
+}
+
+/// Returns whether the system has etm device. ETM device may not be available immediately
+/// after boot.
+pub fn has_device_support() -> bool {
+    unsafe { simpleperf_profcollect_bindgen::HasDeviceSupport() }
 }
 
 /// ETM recording scope