Instrumenting build retrieval and unpacking times

src/clusterfuzz/_internal/build_management/build_manager.py

@@ -34,6 +34,7 @@
 from clusterfuzz._internal.google_cloud_utils import blobs
 from clusterfuzz._internal.google_cloud_utils import storage
 from clusterfuzz._internal.metrics import logs
+from clusterfuzz._internal.metrics import monitoring_metrics
 from clusterfuzz._internal.platforms import android
 from clusterfuzz._internal.system import archive
 from clusterfuzz._internal.system import environment
@@ -431,7 +432,16 @@ def _download_and_open_build_archive(self, base_build_dir: str,
 
     logs.info(f'Downloading build from {build_url} to {build_local_archive}.')
     try:
+      start_time = time.time()
       storage.copy_file_from(build_url, build_local_archive)
+      build_download_duration = time.time() - start_time
+      monitoring_metrics.JOB_BUILD_RETRIEVAL_TIME.add(
+          build_download_duration, {
+              'fuzz_target': self.fuzz_target,
+              'job_type': os.getenv('JOB_TYPE'),
+              'platform': environment.platform(),
+              'step': 'download',
+          })
     except Exception as e:
       logs.error(f'Unable to download build from {build_url}: {e}')
       raise
@@ -475,6 +485,7 @@ def _open_build_archive(self, base_build_dir: str, build_dir: str,
     if not can_unzip_over_http:
       return self._download_and_open_build_archive(base_build_dir, build_dir,
                                                    build_url)
+    # We do not emmit a metric for build download time, if using http
     logs.info("Opening an archive over HTTP, skipping archive download.")
     assert http_build_url
     return build_archive.open_uri(http_build_url)
@@ -550,6 +561,17 @@ def _unpack_build(self,
       utils.write_data_to_file('', partial_build_file_path)
 
     elapsed_time = time.time() - start_time
+    monitoring_metrics.JOB_BUILD_RETRIEVAL_TIME.add(
+        elapsed_time,
+        {
+            # The concept of a fuzz target does not apply
+            # to blackbox fuzzers
+            'fuzz_target': self.fuzz_target,
+            'job_type': os.getenv('JOB_TYPE'),
+            'platform': environment.platform(),
+            'step': 'unpack',
+        })
+
     elapsed_mins = elapsed_time / 60.
     log_func = logs.warning if elapsed_time > UNPACK_TIME_LIMIT else logs.info
     log_func(f'Build took {elapsed_mins:0.02f} minutes to unpack.')
@@ -862,6 +884,9 @@ def _unpack_custom_build(self):
                                        self.custom_binary_filename)
     custom_builds_bucket = local_config.ProjectConfig().get(
         'custom_builds.bucket')
+
+    download_start_time = time.time()
+
     if custom_builds_bucket:
       directory = os.path.dirname(build_local_archive)
       if not os.path.exists(directory):
@@ -872,6 +897,18 @@ def _unpack_custom_build(self):
                                      build_local_archive):
       return False
 
+    build_download_time = time.time() - download_start_time
+    monitoring_metrics.JOB_BUILD_RETRIEVAL_TIME.add(
+        build_download_time,
+        {
+            # The concept of a fuzz target does not apply
+            # to blackbox fuzzers
+            'fuzz_target': 'N/A',
+            'job_type': os.getenv('JOB_TYPE'),
+            'platform': environment.platform(),
+            'step': 'download',
+        })
+
     # If custom binary is an archive, then unpack it.
     if archive.is_archive(self.custom_binary_filename):
       try:
@@ -888,7 +925,20 @@ def _unpack_custom_build(self):
         logs.log_fatal_and_exit('Could not make space for build.')
 
       try:
+        # Unpack belongs to the BuildArchive class
+        unpack_start_time = time.time()
         build.unpack(self.build_dir, trusted=True)
+        build_unpack_time = time.time() - unpack_start_time
+        monitoring_metrics.JOB_BUILD_RETRIEVAL_TIME.add(
+            build_unpack_time,
+            {
+                # The concept of a fuzz target does not apply
+                # to blackbox fuzzers
+                'fuzz_target': 'N/A',
+                'job_type': os.getenv('JOB_TYPE'),
+                'platform': environment.platform(),
+                'step': 'unpack',
+            })
       except:
         build.close()
         logs.error('Unable to unpack build archive %s.' % build_local_archive)

src/clusterfuzz/_internal/metrics/monitoring_metrics.py

@@ -32,6 +32,19 @@
         monitor.BooleanField('bad_build'),
     ])
 
+JOB_BUILD_RETRIEVAL_TIME = monitor.CumulativeDistributionMetric(
+    'task/fuzz/job/build_retrieval_time',
+    bucketer=monitor.FixedWidthBucketer(width=0.05, num_finite_buckets=20),
+    description=('Distribution of fuzz task\'s build retrieval times. '
+                 '(grouped by fuzzer/job)'),
+    field_spec=[
+        monitor.StringField('fuzz_target'),
+        monitor.StringField('job_type'),
+        monitor.StringField('step'),
+        monitor.StringField('platform'),
+    ],
+)
+
 FUZZER_KNOWN_CRASH_COUNT = monitor.CounterMetric(
     'task/fuzz/fuzzer/known_crash_count',
     description=('Count of fuzz task\'s known crash count '

src/clusterfuzz/_internal/tests/core/build_management/build_manager_test.py

@@ -1178,6 +1178,7 @@ def test_setup_shared(self):
   def test_delete(self):
     """Test deleting this build."""
     os.environ['JOB_NAME'] = 'job_custom'
+    self.mock.time.return_value = 1000.0
     build = build_manager.setup_custom_binary()
     self.assertTrue(os.path.isdir('/builds/job_custom/custom'))
     build.delete()