""" Tests for benchmarks/efficiency/speed_profiler.py Tests cover: - SpeedProfiler initialization - Session start/stop - Timer management (start, stop, context manager) - Timing retrieval and summary - time_function decorator """ import time from unittest.mock import patch class TestSpeedProfilerInit: """Tests for SpeedProfiler initialization.""" def test_init_creates_empty_timings(self): """Test that initialization creates empty timings dict.""" from local_deep_research.benchmarks.efficiency.speed_profiler import ( SpeedProfiler, ) profiler = SpeedProfiler() assert profiler.timings == {} def test_init_creates_empty_current_timers(self): """Test that initialization creates empty current_timers dict.""" from local_deep_research.benchmarks.efficiency.speed_profiler import ( SpeedProfiler, ) profiler = SpeedProfiler() assert profiler.current_timers == {} def test_init_total_start_time_is_none(self): """Test that total_start_time is None on init.""" from local_deep_research.benchmarks.efficiency.speed_profiler import ( SpeedProfiler, ) profiler = SpeedProfiler() assert profiler.total_start_time is None def test_init_total_end_time_is_none(self): """Test that total_end_time is None on init.""" from local_deep_research.benchmarks.efficiency.speed_profiler import ( SpeedProfiler, ) profiler = SpeedProfiler() assert profiler.total_end_time is None class TestSpeedProfilerStartStop: """Tests for session start/stop.""" def test_start_sets_total_start_time(self): """Test that start() sets total_start_time.""" from local_deep_research.benchmarks.efficiency.speed_profiler import ( SpeedProfiler, ) profiler = SpeedProfiler() before = time.time() profiler.start() after = time.time() assert profiler.total_start_time is not None assert before <= profiler.total_start_time <= after def test_start_clears_timings(self): """Test that start() clears any existing timings.""" from local_deep_research.benchmarks.efficiency.speed_profiler import ( SpeedProfiler, ) profiler = SpeedProfiler() profiler.timings = {"old_timer": {"total": 1.0}} profiler.current_timers = {"running": time.time()} profiler.start() assert profiler.timings == {} assert profiler.current_timers == {} def test_stop_sets_total_end_time(self): """Test that stop() sets total_end_time.""" from local_deep_research.benchmarks.efficiency.speed_profiler import ( SpeedProfiler, ) profiler = SpeedProfiler() profiler.start() before = time.time() profiler.stop() after = time.time() assert profiler.total_end_time is not None assert before <= profiler.total_end_time <= after def test_stop_stops_running_timers(self): """Test that stop() stops any running timers.""" from local_deep_research.benchmarks.efficiency.speed_profiler import ( SpeedProfiler, ) profiler = SpeedProfiler() profiler.start() profiler.start_timer("running_timer") assert "running_timer" in profiler.current_timers profiler.stop() assert "running_timer" not in profiler.current_timers assert "running_timer" in profiler.timings def test_stop_records_total_duration(self): """Test that stop() allows calculating total duration.""" from local_deep_research.benchmarks.efficiency.speed_profiler import ( SpeedProfiler, ) profiler = SpeedProfiler() profiler.start() time.sleep(0.01) # Small delay profiler.stop() duration = profiler.total_end_time - profiler.total_start_time assert duration >= 0.01 class TestSpeedProfilerTimers: """Tests for timer management.""" def test_start_timer_adds_to_current_timers(self): """Test that start_timer adds timer to current_timers.""" from local_deep_research.benchmarks.efficiency.speed_profiler import ( SpeedProfiler, ) profiler = SpeedProfiler() before = time.time() profiler.start_timer("my_timer") after = time.time() assert "my_timer" in profiler.current_timers assert before <= profiler.current_timers["my_timer"] <= after def test_start_timer_restarts_existing_timer(self): """Test that starting an existing timer restarts it.""" from local_deep_research.benchmarks.efficiency.speed_profiler import ( SpeedProfiler, ) profiler = SpeedProfiler() profiler.start_timer("my_timer") old_time = profiler.current_timers["my_timer"] time.sleep(0.01) profiler.start_timer("my_timer") new_time = profiler.current_timers["my_timer"] assert new_time > old_time def test_stop_timer_removes_from_current_timers(self): """Test that stop_timer removes from current_timers.""" from local_deep_research.benchmarks.efficiency.speed_profiler import ( SpeedProfiler, ) profiler = SpeedProfiler() profiler.start_timer("my_timer") profiler.stop_timer("my_timer") assert "my_timer" not in profiler.current_timers def test_stop_timer_adds_to_timings(self): """Test that stop_timer adds timing data.""" from local_deep_research.benchmarks.efficiency.speed_profiler import ( SpeedProfiler, ) profiler = SpeedProfiler() profiler.start_timer("my_timer") time.sleep(0.01) profiler.stop_timer("my_timer") assert "my_timer" in profiler.timings assert profiler.timings["my_timer"]["count"] == 1 assert profiler.timings["my_timer"]["total"] >= 0.01 def test_stop_timer_accumulates_count(self): """Test that multiple timer runs accumulate count.""" from local_deep_research.benchmarks.efficiency.speed_profiler import ( SpeedProfiler, ) profiler = SpeedProfiler() for _ in range(3): profiler.start_timer("my_timer") profiler.stop_timer("my_timer") assert profiler.timings["my_timer"]["count"] == 3 def test_stop_timer_tracks_min_max(self): """Test that timer tracks min and max values.""" from local_deep_research.benchmarks.efficiency.speed_profiler import ( SpeedProfiler, ) profiler = SpeedProfiler() # First run profiler.start_timer("my_timer") time.sleep(0.01) profiler.stop_timer("my_timer") # Second run profiler.start_timer("my_timer") time.sleep(0.02) profiler.stop_timer("my_timer") assert ( profiler.timings["my_timer"]["min"] < profiler.timings["my_timer"]["max"] ) def test_stop_timer_not_started_does_nothing(self): """Test that stopping a non-existent timer does nothing.""" from local_deep_research.benchmarks.efficiency.speed_profiler import ( SpeedProfiler, ) profiler = SpeedProfiler() profiler.stop_timer("nonexistent") assert "nonexistent" not in profiler.timings def test_timer_context_manager_starts_and_stops(self): """Test timer context manager starts and stops timer.""" from local_deep_research.benchmarks.efficiency.speed_profiler import ( SpeedProfiler, ) profiler = SpeedProfiler() with profiler.timer("context_timer"): assert "context_timer" in profiler.current_timers assert "context_timer" not in profiler.current_timers assert "context_timer" in profiler.timings def test_timer_context_manager_records_time(self): """Test timer context manager records elapsed time.""" from local_deep_research.benchmarks.efficiency.speed_profiler import ( SpeedProfiler, ) profiler = SpeedProfiler() with profiler.timer("context_timer"): time.sleep(0.01) assert profiler.timings["context_timer"]["total"] >= 0.01 class TestSpeedProfilerGetTimings: """Tests for timing retrieval.""" def test_get_timings_returns_copy(self): """Test that get_timings returns a copy of timings.""" from local_deep_research.benchmarks.efficiency.speed_profiler import ( SpeedProfiler, ) profiler = SpeedProfiler() profiler.start_timer("test") profiler.stop_timer("test") result = profiler.get_timings() result["modified"] = True assert "modified" not in profiler.timings def test_get_timings_calculates_averages(self): """Test that get_timings calculates averages.""" from local_deep_research.benchmarks.efficiency.speed_profiler import ( SpeedProfiler, ) profiler = SpeedProfiler() for _ in range(4): profiler.start_timer("test") profiler.stop_timer("test") result = profiler.get_timings() assert "avg" in result["test"] expected_avg = result["test"]["total"] / result["test"]["count"] assert abs(result["test"]["avg"] - expected_avg) < 0.0001 def test_get_timings_includes_total_duration(self): """Test that get_timings includes total session duration.""" from local_deep_research.benchmarks.efficiency.speed_profiler import ( SpeedProfiler, ) profiler = SpeedProfiler() profiler.start() time.sleep(0.01) profiler.stop() result = profiler.get_timings() assert "total" in result assert result["total"]["total"] >= 0.01 def test_get_timings_empty_when_no_timers(self): """Test that get_timings returns empty dict when no timers used.""" from local_deep_research.benchmarks.efficiency.speed_profiler import ( SpeedProfiler, ) profiler = SpeedProfiler() result = profiler.get_timings() assert result == {} class TestSpeedProfilerGetSummary: """Tests for summary generation.""" def test_get_summary_includes_total_duration(self): """Test that summary includes total_duration.""" from local_deep_research.benchmarks.efficiency.speed_profiler import ( SpeedProfiler, ) profiler = SpeedProfiler() profiler.start() time.sleep(0.01) profiler.stop() summary = profiler.get_summary() assert "total_duration" in summary assert summary["total_duration"] >= 0.01 def test_get_summary_calculates_percentages(self): """Test that summary calculates component percentages.""" from local_deep_research.benchmarks.efficiency.speed_profiler import ( SpeedProfiler, ) profiler = SpeedProfiler() profiler.start() with profiler.timer("component"): time.sleep(0.01) profiler.stop() summary = profiler.get_summary() assert "component_percent" in summary assert 0 <= summary["component_percent"] <= 100 def test_get_summary_includes_per_operation_times(self): """Test that summary includes per-operation times.""" from local_deep_research.benchmarks.efficiency.speed_profiler import ( SpeedProfiler, ) profiler = SpeedProfiler() for _ in range(3): profiler.start_timer("op") profiler.stop_timer("op") summary = profiler.get_summary() assert "op_per_operation" in summary def test_get_summary_handles_zero_duration(self): """Test that summary handles zero total duration gracefully.""" from local_deep_research.benchmarks.efficiency.speed_profiler import ( SpeedProfiler, ) profiler = SpeedProfiler() profiler.start_timer("test") profiler.stop_timer("test") # Don't call start/stop, so total_duration comes from sum of timers summary = profiler.get_summary() # Should not raise division by zero assert "total_duration" in summary class TestSpeedProfilerPrintSummary: """Tests for print_summary.""" def test_print_summary_outputs_header(self, capsys): """Test that print_summary outputs header.""" from local_deep_research.benchmarks.efficiency.speed_profiler import ( SpeedProfiler, ) profiler = SpeedProfiler() profiler.start() profiler.stop() profiler.print_summary() captured = capsys.readouterr() assert "SPEED PROFILE SUMMARY" in captured.out def test_print_summary_shows_total_time(self, capsys): """Test that print_summary shows total execution time.""" from local_deep_research.benchmarks.efficiency.speed_profiler import ( SpeedProfiler, ) profiler = SpeedProfiler() profiler.start() time.sleep(0.01) profiler.stop() profiler.print_summary() captured = capsys.readouterr() assert "Total execution time:" in captured.out class TestTimeFunctionDecorator: """Tests for time_function decorator.""" def test_time_function_returns_result(self): """Test that decorated function returns correct result.""" from local_deep_research.benchmarks.efficiency.speed_profiler import ( time_function, ) @time_function def add(a, b): return a + b result = add(2, 3) assert result == 5 def test_time_function_logs_execution_time(self): """Test that decorator logs execution time.""" from local_deep_research.benchmarks.efficiency.speed_profiler import ( time_function, ) @time_function def slow_function(): time.sleep(0.01) return "done" with patch( "local_deep_research.benchmarks.efficiency.speed_profiler.logger" ) as mock_logger: slow_function() mock_logger.info.assert_called_once() call_args = mock_logger.info.call_args[0][0] assert "slow_function" in call_args assert "seconds" in call_args def test_time_function_preserves_args_kwargs(self): """Test that decorator preserves function arguments.""" from local_deep_research.benchmarks.efficiency.speed_profiler import ( time_function, ) @time_function def greet(name, greeting="Hello"): return f"{greeting}, {name}!" result = greet("World", greeting="Hi") assert result == "Hi, World!" class TestSpeedProfilerTimingData: """Tests for timing data structure.""" def test_timing_data_includes_starts_list(self): """Test that timing data includes list of start times.""" from local_deep_research.benchmarks.efficiency.speed_profiler import ( SpeedProfiler, ) profiler = SpeedProfiler() for _ in range(3): profiler.start_timer("test") profiler.stop_timer("test") assert "starts" in profiler.timings["test"] assert len(profiler.timings["test"]["starts"]) == 3 def test_timing_data_includes_durations_list(self): """Test that timing data includes list of durations.""" from local_deep_research.benchmarks.efficiency.speed_profiler import ( SpeedProfiler, ) profiler = SpeedProfiler() for _ in range(3): profiler.start_timer("test") profiler.stop_timer("test") assert "durations" in profiler.timings["test"] assert len(profiler.timings["test"]["durations"]) == 3 def test_timing_data_total_equals_sum_of_durations(self): """Test that total equals sum of individual durations.""" from local_deep_research.benchmarks.efficiency.speed_profiler import ( SpeedProfiler, ) profiler = SpeedProfiler() for _ in range(3): profiler.start_timer("test") time.sleep(0.01) profiler.stop_timer("test") total = profiler.timings["test"]["total"] sum_durations = sum(profiler.timings["test"]["durations"]) assert abs(total - sum_durations) < 0.0001