|
23 | 23 | import subprocess |
24 | 24 | import sys |
25 | 25 | import tempfile |
| 26 | +import time |
26 | 27 | import yaml |
27 | 28 | from datetime import date, datetime |
28 | 29 | from functools import lru_cache |
|
31 | 32 | import build.util |
32 | 33 | import parse_googleapis_content |
33 | 34 |
|
| 35 | +logging.basicConfig(stream=sys.stdout, level=logging.INFO) |
| 36 | + |
| 37 | +import functools |
| 38 | + |
| 39 | +PERF_LOGGING_ENABLED = os.environ.get("ENABLE_PERF_LOGS") == "1" |
| 40 | + |
| 41 | +if PERF_LOGGING_ENABLED: |
| 42 | + perf_logger = logging.getLogger("performance_metrics") |
| 43 | + perf_logger.setLevel(logging.INFO) |
| 44 | + perf_handler = logging.FileHandler("performance_metrics.log", mode='w') |
| 45 | + perf_formatter = logging.Formatter('%(asctime)s | %(message)s', datefmt='%H:%M:%S') |
| 46 | + perf_handler.setFormatter(perf_formatter) |
| 47 | + perf_logger.addHandler(perf_handler) |
| 48 | + perf_logger.propagate = False |
| 49 | + |
| 50 | +def track_time(func): |
| 51 | + """ |
| 52 | + Decorator. Usage: @track_time |
| 53 | + If logging is OFF, it returns the original function (Zero Overhead). |
| 54 | + If logging is ON, it wraps the function to measure execution time. |
| 55 | + """ |
| 56 | + if not PERF_LOGGING_ENABLED: |
| 57 | + return func |
| 58 | + |
| 59 | + @functools.wraps(func) |
| 60 | + def wrapper(*args, **kwargs): |
| 61 | + start_time = time.perf_counter() |
| 62 | + try: |
| 63 | + return func(*args, **kwargs) |
| 64 | + finally: |
| 65 | + duration = time.perf_counter() - start_time |
| 66 | + perf_logger.info(f"{func.__name__:<30} | {duration:.4f} seconds") |
| 67 | + |
| 68 | + return wrapper |
34 | 69 |
|
35 | 70 | try: |
36 | 71 | import synthtool |
@@ -320,6 +355,7 @@ def _get_library_id(request_data: Dict) -> str: |
320 | 355 | return library_id |
321 | 356 |
|
322 | 357 |
|
| 358 | +@track_time |
323 | 359 | def _run_post_processor(output: str, library_id: str, is_mono_repo: bool): |
324 | 360 | """Runs the synthtool post-processor on the output directory. |
325 | 361 |
|
@@ -389,6 +425,7 @@ def _add_header_to_files(directory: str) -> None: |
389 | 425 | f.writelines(lines) |
390 | 426 |
|
391 | 427 |
|
| 428 | +@track_time |
392 | 429 | def _copy_files_needed_for_post_processing( |
393 | 430 | output: str, input: str, library_id: str, is_mono_repo: bool |
394 | 431 | ): |
@@ -435,6 +472,7 @@ def _copy_files_needed_for_post_processing( |
435 | 472 | ) |
436 | 473 |
|
437 | 474 |
|
| 475 | +@track_time |
438 | 476 | def _clean_up_files_after_post_processing( |
439 | 477 | output: str, library_id: str, is_mono_repo: bool |
440 | 478 | ): |
@@ -581,6 +619,7 @@ def _get_repo_name_from_repo_metadata(base: str, library_id: str, is_mono_repo: |
581 | 619 | return repo_name |
582 | 620 |
|
583 | 621 |
|
| 622 | +@track_time |
584 | 623 | def _generate_repo_metadata_file( |
585 | 624 | output: str, library_id: str, source: str, apis: List[Dict], is_mono_repo: bool |
586 | 625 | ): |
@@ -622,6 +661,7 @@ def _generate_repo_metadata_file( |
622 | 661 | _write_json_file(output_repo_metadata, metadata_content) |
623 | 662 |
|
624 | 663 |
|
| 664 | +@track_time |
625 | 665 | def _copy_readme_to_docs(output: str, library_id: str, is_mono_repo: bool): |
626 | 666 | """Copies the README.rst file for a generated library to docs/README.rst. |
627 | 667 |
|
@@ -663,6 +703,7 @@ def _copy_readme_to_docs(output: str, library_id: str, is_mono_repo: bool): |
663 | 703 | f.write(content) |
664 | 704 |
|
665 | 705 |
|
| 706 | +@track_time |
666 | 707 | def handle_generate( |
667 | 708 | librarian: str = LIBRARIAN_DIR, |
668 | 709 | source: str = SOURCE_DIR, |
@@ -924,6 +965,7 @@ def _stage_gapic_library(tmp_dir: str, staging_dir: str) -> None: |
924 | 965 | shutil.copytree(tmp_dir, staging_dir, dirs_exist_ok=True) |
925 | 966 |
|
926 | 967 |
|
| 968 | +@track_time |
927 | 969 | def _generate_api( |
928 | 970 | api_path: str, |
929 | 971 | library_id: str, |
|
0 commit comments