Skip to content

Commit

Permalink
Added comments and changed param
Browse files Browse the repository at this point in the history
  • Loading branch information
TeachMeTW committed Oct 17, 2024
1 parent 1bdc922 commit db1e7bb
Show file tree
Hide file tree
Showing 2 changed files with 56 additions and 21 deletions.
7 changes: 3 additions & 4 deletions emission/storage/decorations/stats_queries.py
Original file line number Diff line number Diff line change
Expand Up @@ -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()
Expand Down
70 changes: 53 additions & 17 deletions emission/tests/storageTests/TestStatsQueries.py
Original file line number Diff line number Diff line change
Expand Up @@ -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),
Expand All @@ -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()

0 comments on commit db1e7bb

Please sign in to comment.