From db1e7bbe8ff40245a74681e447436b3cc6d5ebfb Mon Sep 17 00:00:00 2001 From: TeachMeTW Date: Thu, 17 Oct 2024 13:52:34 -0700 Subject: [PATCH] Added comments and changed param --- emission/storage/decorations/stats_queries.py | 7 +- .../tests/storageTests/TestStatsQueries.py | 70 ++++++++++++++----- 2 files changed, 56 insertions(+), 21 deletions(-) diff --git a/emission/storage/decorations/stats_queries.py b/emission/storage/decorations/stats_queries.py index 5a138a3f6..163384342 100644 --- a/emission/storage/decorations/stats_queries.py +++ b/emission/storage/decorations/stats_queries.py @@ -51,10 +51,9 @@ def store_dashboard_time(code_fragment_name: str, timer: ec_timer.Timer): Stores statistics about execution times in dashboard code using a Timer object. Both of our current dashboards generate _aggregate_ metrics. We do not work at a per-user level in the Python dashboards, so we pass in only the name of the step being instrumented and the timing information. - - Parameters: - - code_fragment_name (str): The name of the function or code fragment being timed. - - timer (ec_timer.Timer): The Timer object that records the execution duration. + + :param code_fragment_name (str): The name of the function or code fragment being timed. + :param timer (ec_timer.Timer): The Timer object that records the execution duration. """ # Get the current timestamp in seconds since epoch timestamp = time.time() diff --git a/emission/tests/storageTests/TestStatsQueries.py b/emission/tests/storageTests/TestStatsQueries.py index 61bdd85ae..e35ed03ec 100644 --- a/emission/tests/storageTests/TestStatsQueries.py +++ b/emission/tests/storageTests/TestStatsQueries.py @@ -29,70 +29,98 @@ def tearDown(self): def verify_stats_entries(self, expected_entries: list[tuple[str, str, float]]): """ - Verifies that each of these expected entries, in the form of (key, name, elapsed_ms), - are stored in the database. + Verifies that each of the expected entries, in the form of (key, name, elapsed_ms), + are stored correctly in the database. - :param expected_entries: A list of tuples which have (key, name, expected_elapsed_ms). + :param expected_entries: A list of tuples containing (key, name, expected_elapsed_ms). """ + # Log the number of entries expected to exist in the database. logging.debug(f"Ensuring {len(expected_entries)} entries exist in DB.") + # Extract the keys from the expected entries for querying the database. key_list = [key for (key, _, _) in expected_entries] + # Retrieve the stored entries from the database matching the keys. stored_entrys = list(self.timeseries_db.find_entries(key_list)) + # Assert that the number of stored entries matches the number of expected entries. self.assertEqual(len(stored_entrys), len(expected_entries)) + # Iterate over each expected entry to verify its correctness. for i in range(len(expected_entries)): stored_entry = stored_entrys[i] expected_key, expected_name, expected_reading = expected_entries[i] + # Log the comparison between expected and stored entries. logging.debug(f"Comparing expected {expected_entries[i]} " + f"with stored {stored_entry['metadata']['key']} {stored_entry['data']}") + # Assert that the stored key matches the expected key. self.assertEqual(stored_entry['metadata']['key'], expected_key) + # Assert that the stored name matches the expected name. self.assertEqual(stored_entry['data']['name'], expected_name) + # Assert that the stored reading (elapsed time) matches the expected value. self.assertEqual(stored_entry['data']['reading'], expected_reading) def test_single_function_timing(self): """ - Test execution and timing of a single function. + Test the execution and timing of a single function. + This test measures how long 'sample_function' takes to execute and verifies + that the timing information is correctly stored in the database. """ def sample_function(): logging.debug("Executing sample_function") - time.sleep(2) # Simulate processing time + time.sleep(2) # Simulate processing time by sleeping for 2 seconds. return True + # Use the Timer context manager to measure the execution time of 'sample_function'. with ect.Timer() as timer: sample_function() + # Store the timing information in the database under the key 'sample_function'. esdsq.store_dashboard_time("sample_function", timer) - # verify that an entry was stored correctly + # Verify that the timing entry was stored correctly in the database. self.verify_stats_entries([ ("stats/dashboard_time", "sample_function", timer.elapsed_ms) ]) def test_multiple_functions_timing(self): """ - Test execution and timing of 2 functions, where we record and validate - the time taken for: (i) function_one, (ii) function_two, and (iii) both functions together. + Test the execution and timing of two functions. + This test records and validates the time taken for: + (i) function_one, + (ii) function_two, and + (iii) both functions together. """ - def function_one(): return time.sleep(1) - def function_two(): return time.sleep(1.5) + def function_one(): + # Simulate processing time by sleeping for 1 second. + return time.sleep(1) + def function_two(): + # Simulate processing time by sleeping for 1.5 seconds. + return time.sleep(1.5) + + # Start the overall timer for both functions. with ect.Timer() as timer_both: + # Start and stop the timer for 'function_one'. with ect.Timer() as timer_one: function_one() + # Store the timing information for 'function_one'. esdsq.store_dashboard_time("function_one", timer_one) + # Start and stop the timer for 'function_two'. with ect.Timer() as timer_two: function_two() + # Store the timing information for 'function_two'. esdsq.store_dashboard_time("function_two", timer_two) + # Store the combined timing information for both functions. esdsq.store_dashboard_time("functions_one_and_two", timer_both) - # function_one should've taken ~1000ms; function_two should've taken ~1500ms; - # both functions together should've taken ~2500ms + # Assert that the elapsed time for 'function_one' is approximately 1000ms (1 second). self.assertAlmostEqual(timer_one.elapsed_ms, 1000, delta=100) + # Assert that the elapsed time for 'function_two' is approximately 1500ms (1.5 seconds). self.assertAlmostEqual(timer_two.elapsed_ms, 1500, delta=100) + # Assert that the combined elapsed time is approximately 2500ms (2.5 seconds). self.assertAlmostEqual(timer_both.elapsed_ms, 2500, delta=100) - # verify that entries were stored correctly + # Verify that all timing entries were stored correctly in the database. self.verify_stats_entries([ ("stats/dashboard_time", "function_one", timer_one.elapsed_ms), ("stats/dashboard_time", "function_two", timer_two.elapsed_ms), @@ -101,28 +129,36 @@ def function_two(): return time.sleep(1.5) def test_faulty_function_timing(self): """ - Test execution and timing of a faulty function that is expected to - raise an exception. + Test the execution and timing of a faulty function that is expected to raise an exception. + This test ensures that even when a function fails, the timing information is correctly + recorded as an error in the database. """ def faulty_function(): logging.debug("Executing faulty_function") - time.sleep(1) # Simulate processing time before failure + time.sleep(1) # Simulate processing time before failure. raise ValueError("Simulated error in faulty_function") try: + # Attempt to execute the faulty function while timing its execution. with ect.Timer() as timer: faulty_function() except ValueError as e: + # Catch the expected ValueError exception. logging.info(f"Caught expected error: {e}") + # Store the timing information as an error in the database under 'faulty_function'. esdsq.store_dashboard_error('faulty_function', timer) + # Pass to continue execution after handling the exception. pass - # verify that an entry was stored correctly + # Verify that the error timing entry was stored correctly in the database. self.verify_stats_entries([ ("stats/dashboard_error", "faulty_function", timer.elapsed_ms) ]) if __name__ == '__main__': + # Configure logging settings before running the tests. etc.configLogging() + # Run all the test cases defined in the TestFunctionTiming class. unittest.main() + \ No newline at end of file