arc: Add some debug logs for vmm manager

This CL add some debug logs for vmm manager, in order to make the
local debugging easier.

BUG=b:265383671

Change-Id: Ia9c92554e9802eeadbfa478de65cee1580e4f7eb
Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/4573490
Reviewed-by: Yuichiro Hanada <yhanada@chromium.org>
Commit-Queue: Shengsong Tan <sstan@chromium.org>
Cr-Commit-Position: refs/heads/main@{#1150413}

chrome/browser/ash/arc/vmm/arc_system_state_observation.cc

@@ -49,6 +49,7 @@ void ArcSystemStateObservation::ThrottleInstance(bool should_throttle) {
   // ARC system or app is active.
   if (!should_throttle) {
     last_peace_timestamp_.reset();
+    DVLOG(1) << "ARC is active, reset peace timestamp.";
     if (!active_callback_.is_null()) {
       active_callback_.Run();
     }
@@ -60,6 +61,8 @@ void ArcSystemStateObservation::ThrottleInstance(bool should_throttle) {
   if (arc_connected_) {
     // ARC system and app is not active.
     last_peace_timestamp_ = base::Time::Now();
+    DVLOG(1) << "ARC is not active, time recording start at "
+             << last_peace_timestamp_.value();
   }
 }
 

chrome/browser/ash/arc/vmm/arc_vmm_manager.cc

@@ -104,6 +104,7 @@ void ArcVmmManager::SetSwapState(SwapState state) {
     LOG(ERROR) << "Failed to SetSwapState, ARCVM not enabled or connected.";
     return;
   }
+  DVLOG(1) << "SetSwapState " << static_cast<int>(state);
   vm_tools::concierge::SwapOperation op;
   switch (state) {
     case SwapState::ENABLE:
@@ -191,6 +192,8 @@ void ArcVmmManager::SendSwapRequest(
     return;
   }
 
+  DVLOG(1) << "SendSwapRequest " << static_cast<int>(operation)
+           << " to concierge.";
   vm_tools::concierge::SwapVmRequest request;
   request.set_name(kArcVmName);
   request.set_owner_id(user_id_hash_);
@@ -220,6 +223,8 @@ void ArcVmmManager::SendAggressiveBalloonRequest(
     return;
   }
 
+  DVLOG(1) << "SendAggressiveBalloon state change " << enable
+           << " request to concierge";
   vm_tools::concierge::AggressiveBalloonRequest request;
   request.set_name(kArcVmName);
   request.set_owner_id(user_id_hash_);
@@ -251,6 +256,8 @@ void ArcVmmManager::ShrinkArcVmMemoryAndEnableSwap(
   // Trim ARCVM memory before enable vmm swap in order to squeeze the vm
   // memory. Send enable operation if trim success.
   DCHECK(!trim_call_.is_null());
+  DVLOG(1) << "ShrinkArcVmMemoryAndEnableSwap with request "
+           << static_cast<int>(requested_operation);
   trim_call_.Run(
       base::BindOnce(
           [](base::OnceClosure success_closure, bool success,

chrome/browser/ash/arc/vmm/arc_vmm_swap_scheduler.cc

@@ -96,6 +96,9 @@ void ArcVmmSwapScheduler::UpdateSwappableStateByObservation() {
     if (!last_swap_out_time.is_null()) {
       auto past = base::Time::Now() - last_swap_out_time;
       if (past < minimum_swapout_interval_) {
+        DVLOG(1) << "Swappable checking be throttled due to last swap on "
+                 << last_swap_out_time
+                 << " is not meet time interval requirement.";
         return;
       }
     }