80 lines
2.9 KiB
Python
80 lines
2.9 KiB
Python
import sys
|
|
import unittest
|
|
from pathlib import Path
|
|
from unittest import mock
|
|
|
|
sys.path.insert(0, str(Path(__file__).resolve().parents[1] / "src"))
|
|
|
|
from cthulhu import debug
|
|
|
|
|
|
class DebugStartupTimingTests(unittest.TestCase):
|
|
def setUp(self) -> None:
|
|
self._debugLevel = debug.debugLevel
|
|
self._startupTimingEnabled = debug.startupTimingEnabled
|
|
self._startupTimingStartTime = debug._startupTimingStartTime
|
|
self._startupTimingLastTime = debug._startupTimingLastTime
|
|
debug.debugLevel = debug.LEVEL_SEVERE
|
|
debug.startupTimingEnabled = False
|
|
debug._startupTimingStartTime = None
|
|
debug._startupTimingLastTime = None
|
|
|
|
def tearDown(self) -> None:
|
|
debug.debugLevel = self._debugLevel
|
|
debug.startupTimingEnabled = self._startupTimingEnabled
|
|
debug._startupTimingStartTime = self._startupTimingStartTime
|
|
debug._startupTimingLastTime = self._startupTimingLastTime
|
|
|
|
def test_startup_timing_is_silent_when_disabled_and_debug_is_not_enabled(self) -> None:
|
|
with mock.patch.object(debug, "println") as println:
|
|
debug.print_startup_timing("hidden phase")
|
|
|
|
println.assert_not_called()
|
|
|
|
def test_startup_timing_logs_when_explicitly_enabled(self) -> None:
|
|
with mock.patch.object(debug.time, "monotonic", side_effect=[10.0, 10.25]):
|
|
debug.set_startup_timing_enabled(True)
|
|
with mock.patch.object(debug, "println") as println:
|
|
debug.print_startup_timing("explicit phase")
|
|
|
|
println.assert_called_once_with(
|
|
debug.LEVEL_SEVERE,
|
|
"STARTUP TIMING: explicit phase: +0.250s, total 0.250s",
|
|
True,
|
|
False,
|
|
)
|
|
|
|
def test_startup_timing_logs_when_debug_output_is_enabled(self) -> None:
|
|
debug.debugLevel = debug.LEVEL_INFO
|
|
with mock.patch.object(debug.time, "monotonic", return_value=20.0):
|
|
with mock.patch.object(debug, "println") as println:
|
|
debug.print_startup_timing("debug phase")
|
|
|
|
println.assert_called_once_with(
|
|
debug.LEVEL_INFO,
|
|
"STARTUP TIMING: debug phase: +0.000s, total 0.000s",
|
|
True,
|
|
False,
|
|
)
|
|
|
|
def test_startup_timing_context_logs_start_and_end(self) -> None:
|
|
with mock.patch.object(debug.time, "monotonic", side_effect=[30.0, 30.1, 30.4]):
|
|
debug.set_startup_timing_enabled(True)
|
|
with mock.patch.object(debug, "println") as println:
|
|
with debug.startup_timing("wrapped phase"):
|
|
pass
|
|
|
|
self.assertEqual(2, println.call_count)
|
|
self.assertEqual(
|
|
"STARTUP TIMING: wrapped phase start: +0.100s, total 0.100s",
|
|
println.call_args_list[0].args[1],
|
|
)
|
|
self.assertEqual(
|
|
"STARTUP TIMING: wrapped phase end: +0.300s, total 0.400s",
|
|
println.call_args_list[1].args[1],
|
|
)
|
|
|
|
|
|
if __name__ == "__main__":
|
|
unittest.main()
|