From 8fd0fa44d46f9f83165619ae90cb3687a70501a1 Mon Sep 17 00:00:00 2001
From: arvidn <arvid@libtorrent.org>
Date: Tue, 26 Dec 2023 14:14:29 +0100
Subject: [PATCH] add feature to profile just the block validation. This
 exposes what is actually going on while we validate blocks. Sometimes the
 block validation times are affected by other tasks that hog the CPU, blocking
 the main co-routine from being scheduled

---
 chia/full_node/full_node.py   | 16 ++++++++++++++--
 chia/util/initial-config.yaml |  5 +++++
 chia/util/profiler.py         | 14 ++++++++++++++
 3 files changed, 33 insertions(+), 2 deletions(-)

diff --git a/chia/full_node/full_node.py b/chia/full_node/full_node.py
index 6fb829a9496e..58bef83ef523 100644
--- a/chia/full_node/full_node.py
+++ b/chia/full_node/full_node.py
@@ -94,7 +94,7 @@
 from chia.util.limited_semaphore import LimitedSemaphore
 from chia.util.log_exceptions import log_exceptions
 from chia.util.path import path_from_root
-from chia.util.profiler import mem_profile_task, profile_task
+from chia.util.profiler import enable_profiler, mem_profile_task, profile_task
 from chia.util.safe_cancel_task import cancel_task_safe
 
 
@@ -288,6 +288,11 @@ async def manage(self) -> AsyncIterator[None]:
             if self.config.get("enable_profiler", False):
                 asyncio.create_task(profile_task(self.root_path, "node", self.log))
 
+            self.profile_block_validation = self.config.get("profile_block_validation", False)
+            if self.profile_block_validation:  # pragma: no cover
+                profile_dir = path_from_root(self.root_path, "block-validation-profile")
+                profile_dir.mkdir(parents=True, exist_ok=True)
+
             if self.config.get("enable_memory_profiler", False):
                 asyncio.create_task(mem_profile_task(self.root_path, "node", self.log))
 
@@ -1706,7 +1711,9 @@ async def add_block(
                 return await self.add_block(new_block, peer)
         state_change_summary: Optional[StateChangeSummary] = None
         ppp_result: Optional[PeakPostProcessingResult] = None
-        async with self.blockchain.priority_mutex.acquire(priority=BlockchainMutexPriority.high):
+        async with self.blockchain.priority_mutex.acquire(priority=BlockchainMutexPriority.high), enable_profiler(
+            self.profile_block_validation
+        ) as pr:
             # After acquiring the lock, check again, because another asyncio thread might have added it
             if self.blockchain.contains_block(header_hash):
                 return None
@@ -1799,6 +1806,11 @@ async def add_block(
             f"{percent_full_str} header_hash: {header_hash} height: {block.height}",
         )
 
+        if validation_time > 2 and pr is not None:  # pragma: no cover
+            pr.create_stats()
+            profile_dir = path_from_root(self.root_path, "block-validation-profile")
+            pr.dump_stats(profile_dir / f"{block.height}-{validation_time:0.1f}.profile")
+
         # This code path is reached if added == ADDED_AS_ORPHAN or NEW_TIP
         peak = self.blockchain.get_peak()
         assert peak is not None
diff --git a/chia/util/initial-config.yaml b/chia/util/initial-config.yaml
index a83ef832ecbd..fa351891832e 100644
--- a/chia/util/initial-config.yaml
+++ b/chia/util/initial-config.yaml
@@ -440,6 +440,11 @@ full_node:
   # analyze with chia/utils/profiler.py
   enable_profiler: False
 
+  # when enabled, each time a block is validated, the python profiler is
+  # engaged. If the validation takes more than 2 seconds, the profile is saved
+  # to disk, in the chia root/block-validation-profile
+  profile_block_validation: False
+
   enable_memory_profiler: False
 
   # this is a debug and profiling facility that logs all SQLite commands to a
diff --git a/chia/util/profiler.py b/chia/util/profiler.py
index 5c7fe74defb4..6716d8fd7c18 100644
--- a/chia/util/profiler.py
+++ b/chia/util/profiler.py
@@ -5,7 +5,9 @@
 import logging
 import pathlib
 import tracemalloc
+from contextlib import asynccontextmanager
 from datetime import datetime
+from typing import AsyncIterator, Optional
 
 from chia.util.path import path_from_root
 
@@ -176,3 +178,15 @@ async def mem_profile_task(root_path: pathlib.Path, service: str, log: logging.L
             counter += 1
     finally:
         tracemalloc.stop()
+
+
+@asynccontextmanager
+async def enable_profiler(profile: bool) -> AsyncIterator[Optional[cProfile.Profile]]:
+    if not profile:
+        yield None
+        return
+
+    with cProfile.Profile() as pr:  # pragma: no cover
+        pr.enable()
+        yield pr
+        pr.disable()