Report duration of complete_step with --debug

diff --git a/mkosi/log.py b/mkosi/log.py
index 61a7fe8ba2dbb04e0c95c09c600800255e49fe87..ddfd185b2e8a75bb47fbe42a63cf69cde89a7d0b 100644 (file)
--- a/mkosi/log.py
+++ b/mkosi/log.py
@@ -5,6 +5,7 @@ import contextvars
 import logging
 import os
 import sys
+import time
 from collections.abc import Iterator
 from typing import Any, NoReturn, Optional
 
@@ -98,6 +99,7 @@ def complete_step(text: str, text2: Optional[str] = None) -> Iterator[list[Any]]
     global LEVEL
 
     log_step(text)
+    start = time.perf_counter()
 
     LEVEL += 1
     try:
@@ -110,6 +112,8 @@ def complete_step(text: str, text2: Optional[str] = None) -> Iterator[list[Any]]
     if text2 is not None:
         log_step(text2.format(*args))
 
+    logging.debug(f'{" " * (LEVEL)}{time.perf_counter() - start:.1f}s for step "{text}"')
+
 
 class Formatter(logging.Formatter):
     def __init__(self, fmt: Optional[str] = None, *args: Any, **kwargs: Any) -> None: