Add extra timing loggers for image writing

Used to diagnose image writer performance.

Bug: 77719042
Test: test-art-host
Change-Id: Iba73eec94a3de33813261b04e497c8857e339d89

4 files changed, 17 insertions, 6 deletions

diff --git a/dex2oat/dex2oat.cc b/dex2oat/dex2oat.cc
index ac5dd61062..efadc3dfc4 100644
--- a/dex2oat/dex2oat.cc
+++ b/dex2oat/dex2oat.cc
@@ -2026,7 +2026,7 @@ class Dex2Oat FINAL {
 
       // We need to prepare method offsets in the image address space for direct method patching.
       TimingLogger::ScopedTiming t2("dex2oat Prepare image address space", timings_);
-      if (!image_writer_->PrepareImageAddressSpace()) {
+      if (!image_writer_->PrepareImageAddressSpace(timings_)) {
         LOG(ERROR) << "Failed to prepare image address space.";
         return false;
       }
diff --git a/dex2oat/linker/image_test.h b/dex2oat/linker/image_test.h
index 7449191984..7490485eb3 100644
--- a/dex2oat/linker/image_test.h
+++ b/dex2oat/linker/image_test.h
@@ -293,7 +293,7 @@ inline void CompilationHelper::Compile(CompilerDriver* driver,
           ASSERT_TRUE(cur_opened_dex_files.empty());
         }
       }
-      bool image_space_ok = writer->PrepareImageAddressSpace();
+      bool image_space_ok = writer->PrepareImageAddressSpace(&timings);
       ASSERT_TRUE(image_space_ok);
 
       DCHECK_EQ(vdex_files.size(), oat_files.size());
diff --git a/dex2oat/linker/image_writer.cc b/dex2oat/linker/image_writer.cc
index 6530ead2d1..c7a30a06ed 100644
--- a/dex2oat/linker/image_writer.cc
+++ b/dex2oat/linker/image_writer.cc
@@ -133,23 +133,31 @@ static void ClearDexFileCookies() REQUIRES_SHARED(Locks::mutator_lock_) {
   Runtime::Current()->GetHeap()->VisitObjects(visitor);
 }
 
-bool ImageWriter::PrepareImageAddressSpace() {
+bool ImageWriter::PrepareImageAddressSpace(TimingLogger* timings) {
   target_ptr_size_ = InstructionSetPointerSize(compiler_driver_.GetInstructionSet());
   gc::Heap* const heap = Runtime::Current()->GetHeap();
   {
     ScopedObjectAccess soa(Thread::Current());
-    PruneNonImageClasses();  // Remove junk
+    {
+      TimingLogger::ScopedTiming t("PruneNonImageClasses", timings);
+      PruneNonImageClasses();  // Remove junk
+    }
     if (compile_app_image_) {
+      TimingLogger::ScopedTiming t("ClearDexFileCookies", timings);
       // Clear dex file cookies for app images to enable app image determinism. This is required
       // since the cookie field contains long pointers to DexFiles which are not deterministic.
       // b/34090128
       ClearDexFileCookies();
     } else {
+      TimingLogger::ScopedTiming t("ComputeLazyFieldsForImageClasses", timings);
       // Avoid for app image since this may increase RAM and image size.
       ComputeLazyFieldsForImageClasses();  // Add useful information
     }
   }
-  heap->CollectGarbage(/* clear_soft_references */ false);  // Remove garbage.
+  {
+    TimingLogger::ScopedTiming t("CollectGarbage", timings);
+    heap->CollectGarbage(/* clear_soft_references */ false);  // Remove garbage.
+  }
 
   if (kIsDebugBuild) {
     ScopedObjectAccess soa(Thread::Current());
@@ -157,12 +165,14 @@ bool ImageWriter::PrepareImageAddressSpace() {
   }
 
   {
+    TimingLogger::ScopedTiming t("CalculateNewObjectOffsets", timings);
     ScopedObjectAccess soa(Thread::Current());
     CalculateNewObjectOffsets();
   }
 
   // This needs to happen after CalculateNewObjectOffsets since it relies on intern_table_bytes_ and
   // bin size sums being calculated.
+  TimingLogger::ScopedTiming t("AllocMemory", timings);
   if (!AllocMemory()) {
     return false;
   }
diff --git a/dex2oat/linker/image_writer.h b/dex2oat/linker/image_writer.h
index c67835b455..197253e102 100644
--- a/dex2oat/linker/image_writer.h
+++ b/dex2oat/linker/image_writer.h
@@ -64,6 +64,7 @@ class ClassLoader;
 class ClassLoaderVisitor;
 class ImTable;
 class ImtConflictTable;
+class TimingLogger;
 
 static constexpr int kInvalidFd = -1;
 
@@ -81,7 +82,7 @@ class ImageWriter FINAL {
               const std::unordered_map<const DexFile*, size_t>& dex_file_oat_index_map,
               const std::unordered_set<std::string>* dirty_image_objects);
 
-  bool PrepareImageAddressSpace();
+  bool PrepareImageAddressSpace(TimingLogger* timings);
 
   bool IsImageAddressSpaceReady() const {
     DCHECK(!image_infos_.empty());