diff --git a/tests/integration/testmanager.nim b/tests/integration/testmanager.nim index 22a700a5..7b829d8b 100644 --- a/tests/integration/testmanager.nim +++ b/tests/integration/testmanager.nim @@ -1,8 +1,10 @@ import std/os import std/strformat +import std/strutils +import std/terminal +import std/unittest import pkg/chronos import pkg/chronos/asyncproc -import pkg/codex/utils/exceptions import pkg/codex/logutils import pkg/questionable import pkg/questionable/results @@ -20,16 +22,24 @@ type lastCodexDiscPort: int debugTestHarness: bool # output chronicles logs for the manager and multinodes harness debugHardhat: bool + debugCodexNodes: bool # output chronicles logs for the codex nodes running in the tests timeStart: Moment timeEnd: Moment codexPortLock: AsyncLock hardhatPortLock: AsyncLock + testTimeout: Duration # individual test timeout IntegrationTestConfig* = object startHardhat*: bool testFile*: string name*: string + IntegrationTestStatus* = enum ## The status of a test when it is done. + OK, + FAILED, + TIMEOUT, + ERROR + IntegrationTest = ref object config: IntegrationTestConfig process: Future[CommandExResponse].Raising([AsyncProcessError, AsyncProcessTimeoutError, CancelledError]) @@ -37,19 +47,27 @@ type timeEnd: Moment output: ?!CommandExResponse testId: string # when used in datadir path, prevents data dir clashes + status: IntegrationTestStatus TestManagerError = object of CatchableError + FormattingError = object of TestManagerError + LockError = object of TestManagerError {.push raises: [].} logScope: topics = "testing integration testmanager" -func new*( +proc raiseTestManagerError(msg: string, parent: ref CatchableError = nil) {.raises: [TestManagerError].} = + raise newException(TestManagerError, msg, parent) + +proc new*( _: type TestManager, configs: seq[IntegrationTestConfig], debugTestHarness = false, - debugHardhat = false): TestManager = + debugHardhat = false, + debugCodexNodes = false, + testTimeout = 60.minutes): TestManager = TestManager( configs: configs, @@ -57,12 +75,11 @@ func new*( lastCodexApiPort: 8000, lastCodexDiscPort: 9000, debugTestHarness: debugTestHarness, - debugHardhat: debugHardhat + debugHardhat: debugHardhat, + debugCodexNodes: debugCodexNodes, + testTimeout: testTimeout ) -proc raiseTestManagerError(msg: string, parent: ref CatchableError = nil) {.raises: [TestManagerError].} = - raise newException(TestManagerError, msg, parent) - template withLock*(lock: AsyncLock, body: untyped) = if lock.isNil: lock = newAsyncLock() @@ -74,8 +91,20 @@ template withLock*(lock: AsyncLock, body: untyped) = finally: try: lock.release() - except AsyncLockError as e: - raiseAssert "failed to release lock, error: " & e.msg + except AsyncLockError as parent: + raiseTestManagerError "lock error", parent + +template styledEcho*(args: varargs[untyped]) = + try: + styledEcho args + except CatchableError as parent: + raiseTestManagerError "failed to print to terminal, error: " & parent.msg, parent + +proc duration(manager: TestManager): Duration = + manager.timeEnd - manager.timeStart + +proc duration(test: IntegrationTest): Duration = + test.timeEnd - test.timeStart proc startHardhat( manager: TestManager, @@ -105,44 +134,57 @@ proc startHardhat( except CatchableError as e: raiseTestManagerError "hardhat node failed to start: " & e.msg, e -proc printOutput(manager: TestManager, test: IntegrationTest) = - without output =? test.output, error: - echo "[FATAL] Test '", test.config.name, "' failed to run to completion" - echo " Error: ", error.msg - echo " Stacktrace: ", error.getStackTrace() - return +proc printResult( + test: IntegrationTest, + colour: ForegroundColor) {.raises: [TestManagerError].} = - if output.status != 0: - if manager.debugTestHarness: - echo output.stdError - echo output.stdOutput - echo "[FAILED] Test '", test.config.name, "' failed" + styledEcho styleBright, colour, &"[{test.status}] ", + resetStyle, test.config.name, + resetStyle, styleDim, &" ({test.duration})" - else: - echo output.stdOutput - echo "[OK] Test '", test.config.name, "' succeeded" +proc printResult( + test: IntegrationTest, + processOutput = false, + testHarnessErrors = false) {.raises: [TestManagerError].} = -proc runTest(manager: TestManager, config: IntegrationTestConfig) {.async: (raises: [CancelledError]).} = - logScope: - config + if test.status == IntegrationTestStatus.ERROR and + error =? test.output.errorOption: + test.printResult(fgRed) + if testHarnessErrors: + echo "Error during test execution: ", error.msg + echo "Stacktrace: ", error.getStackTrace() - trace "Running test" + elif test.status == IntegrationTestStatus.FAILED: + if output =? test.output: + if testHarnessErrors: #manager.debugTestHarness + echo output.stdError + if processOutput: + echo output.stdOutput + test.printResult(fgRed) - var test = IntegrationTest( - config: config, - testId: $ uint16.example - ) + elif test.status == IntegrationTestStatus.TIMEOUT: + test.printResult(fgYellow) - var hardhatPort = 0 - if config.startHardhat: - try: - hardhatPort = await manager.startHardhat(config) - except TestManagerError as e: - e.msg = "Failed to start hardhat: " & e.msg - test.output = CommandExResponse.failure(e) + elif test.status == IntegrationTestStatus.OK: + if processOutput and + output =? test.output: + echo output.stdOutput + test.printResult(fgGreen) + +proc printSummary(test: IntegrationTest) {.raises: [TestManagerError].} = + test.printResult(processOutput = false, testHarnessErrors = false) + +proc printStart(test: IntegrationTest) {.raises: [TestManagerError].} = + styledEcho styleBright, fgMagenta, &"[Integration test started] ", resetStyle, test.config.name + +proc buildCommand( + manager: TestManager, + test: IntegrationTest, + hardhatPort: int): Future[string] {.async: (raises:[CancelledError, TestManagerError]).} = var apiPort, discPort: int withLock(manager.codexPortLock): + # TODO: needed? nextFreePort should take care of this # inc by 20 to allow each test to run 20 codex nodes (clients, SPs, # validators) giving a good chance the port will be free apiPort = await nextFreePort(manager.lastCodexApiPort + 20) @@ -160,70 +202,114 @@ proc runTest(manager: TestManager, config: IntegrationTestConfig) {.async: (rais var testFile: string try: testFile = absolutePath( - config.testFile, + test.config.testFile, root = currentSourcePath().parentDir().parentDir()) - except ValueError as e: - raiseAssert "bad file name, testFile: " & config.testFile & ", error: " & e.msg + except ValueError as parent: + raiseTestManagerError "bad file name, testFile: " & test.config.testFile, parent var command: string - try: - withLock(manager.hardhatPortLock): - command = "nim c " & - &"-d:CodexApiPort={apiPort} " & - &"-d:CodexDiscPort={discPort} " & - (if config.startHardhat: + withLock(manager.hardhatPortLock): + try: + return "nim c " & + &"-d:CodexApiPort={apiPort} " & + &"-d:CodexDiscPort={discPort} " & + (if test.config.startHardhat: &"-d:HardhatPort={hardhatPort} " else: "") & - &"-d:TestId={test.testId} " & - &"{logging} " & + &"-d:TestId={test.testId} " & + &"{logging} " & "--verbosity:0 " & "--hints:off " & "-d:release " & "-r " & - &"{testFile}" - except ValueError as e: - raiseAssert "bad command" & - ", apiPort: " & $apiPort & - ", discPort: " & $discPort & - ", logging: " & logging & - ", testFile: " & testFile & - ", error: " & e.msg - trace "Starting parallel integration test", command + &"{testFile}" + except ValueError as parent: + raiseTestManagerError "bad command --\n" & + ", apiPort: " & $apiPort & + ", discPort: " & $discPort & + ", logging: " & logging & + ", testFile: " & testFile & + ", error: " & parent.msg, + parent +proc runTest( + manager: TestManager, + config: IntegrationTestConfig) {.async: (raises: [CancelledError, TestManagerError]).} = + + logScope: + config + + trace "Running test" + + var test = IntegrationTest( + config: config, + testId: $ uint16.example + ) + + var hardhatPort = 0 + if config.startHardhat: + try: + hardhatPort = await manager.startHardhat(config) + except TestManagerError as e: + e.msg = "Failed to start hardhat: " & e.msg + test.timeEnd = Moment.now() + test.status = IntegrationTestStatus.ERROR + test.output = CommandExResponse.failure(e) + + let command = await manager.buildCommand(test, hardhatPort) + + trace "Starting parallel integration test", command + test.printStart() test.timeStart = Moment.now() test.process = execCommandEx( command = command, - # options = {AsyncProcessOption.StdErrToStdOut, AsyncProcessOption.EvalCommand}, - timeout = 60.minutes + timeout = manager.testTimeout ) manager.tests.add test try: - test.output = success(await test.process) # waits on waitForExit + + let output = await test.process # waits on waitForExit + test.output = success(output) test.timeEnd = Moment.now() - # echo "[OK] Test '" & config.name & "' completed in ", test.timeEnd - test.timeStart + info "Test completed", name = config.name, duration = test.timeEnd - test.timeStart - manager.printOutput(test) + + if output.status != 0: + test.status = IntegrationTestStatus.FAILED + else: + test.status = IntegrationTestStatus.OK + + test.printResult(processOutput = manager.debugCodexNodes, + testHarnessErrors = manager.debugTestHarness) + except CancelledError as e: raise e + except AsyncProcessTimeoutError as e: test.timeEnd = Moment.now() - # echo "[TIMEOUT] Test '" & config.name & "' timed out in ", test.timeEnd - test.timeStart error "Test timed out", name = config.name, duration = test.timeEnd - test.timeStart test.output = CommandExResponse.failure(e) - manager.printOutput(test) + test.status = IntegrationTestStatus.TIMEOUT + test.printResult(processOutput = manager.debugCodexNodes, + testHarnessErrors = manager.debugTestHarness) + except AsyncProcessError as e: test.timeEnd = Moment.now() - # echo "[FAILED] Test '" & config.name & "' failed in ", test.timeEnd - test.timeStart error "Test failed to complete", name = config.name,duration = test.timeEnd - test.timeStart test.output = CommandExResponse.failure(e) - manager.printOutput(test) + test.status = IntegrationTestStatus.ERROR + test.printResult(processOutput = manager.debugCodexNodes, + testHarnessErrors = manager.debugTestHarness) -proc runTests(manager: TestManager) {.async: (raises: [CancelledError]).} = - var testFutures: seq[Future[void].Raising([CancelledError])] +proc runTests(manager: TestManager) {.async: (raises: [CancelledError, TestManagerError]).} = + var testFutures: seq[Future[void].Raising([CancelledError, TestManagerError])] manager.timeStart = Moment.now() + styledEcho styleBright, bgWhite, fgBlack, + "[Integration Test Manager] Starting parallel integration tests" + for config in manager.configs: testFutures.add manager.runTest(config) @@ -231,37 +317,54 @@ proc runTests(manager: TestManager) {.async: (raises: [CancelledError]).} = manager.timeEnd = Moment.now() -proc printOutput(manager: TestManager) = - var successes = 0 - echo "▢=====================================================================▢" - echo "| TEST SUMMARY |" - echo "|" - for test in manager.tests: - without output =? test.output: - echo "| [FATAL] Test '", test.config.name, "' failed to run to completion" - continue - if output.status != 0: - echo "| [FAILED] Test '", test.config.name, "' failed" - else: - echo "| [OK] Test '", test.config.name, "' succeeded" - inc successes +type + Border {.pure.} = enum + Left, Right + Align {.pure.} = enum + Left, Right - echo "| |" - echo "| PASSING : ", successes, " / ", manager.tests.len - let totalDuration = manager.timeEnd - manager.timeStart - echo "| TOTAL TIME : ", totalDuration +proc withBorder( + msg: string, + align = Align.Left, + width = 67, + borders = {Border.Left, Border.Right}): string = + + if borders.contains(Border.Left): + result &= "| " + if align == Align.Left: + result &= msg.alignLeft(width) + elif align == Align.Right: + result &= msg.align(width) + if borders.contains(Border.Right): + result &= " |" + +proc printResult(manager: TestManager) {.raises: [TestManagerError].}= + var successes = 0 var totalDurationSerial: Duration for test in manager.tests: - totalDurationSerial += (test.timeEnd - test.timeStart) + totalDurationSerial += test.duration + if test.status == IntegrationTestStatus.OK: + inc successes # estimated time saved as serial execution with a single hardhat instance # incurs less overhead - echo "| EST TOTAL TIME IF RUN SERIALLY: ", totalDurationSerial - echo "| EST TIME SAVED (ROUGH) : ", totalDurationSerial - totalDuration + let relativeTimeSaved = ((totalDurationSerial - manager.duration).nanos * 100) div + (totalDurationSerial.nanos) + let passingStyle = if successes < manager.tests.len: + fgRed + else: + fgGreen + + echo "\n▢=====================================================================▢" + styledEcho "| ", styleBright, styleUnderscore, "INTEGRATION TEST SUMMARY", resetStyle, "".withBorder(Align.Right, 43, {Border.Right}) + echo "".withBorder() + styledEcho styleBright, "| TOTAL TIME : ", resetStyle, ($manager.duration).withBorder(Align.Right, 49, {Border.Right}) + styledEcho styleBright, "| TIME SAVED (EST): ", resetStyle, (&"{relativeTimeSaved}%").withBorder(Align.Right, 49, {Border.Right}) + styledEcho "| ", styleBright, passingStyle, "PASSING : ", resetStyle, passingStyle, (&"{successes} / {manager.tests.len}").align(49), resetStyle, " |" echo "▢=====================================================================▢" -proc start*(manager: TestManager) {.async: (raises: [CancelledError]).} = +proc start*(manager: TestManager) {.async: (raises: [CancelledError, TestManagerError]).} = await manager.runTests() - manager.printOutput() + manager.printResult() proc stop*(manager: TestManager) {.async: (raises: [CancelledError]).} = for test in manager.tests: diff --git a/tests/testIntegration.nim b/tests/testIntegration.nim index 0f2fe3d5..3a298c22 100644 --- a/tests/testIntegration.nim +++ b/tests/testIntegration.nim @@ -39,7 +39,11 @@ const TestConfigs = proc run() {.async.} = let manager = TestManager.new( - configs = TestConfigs, debugTestHarness = true, debugHardhat = false + configs = TestConfigs, + debugTestHarness = true, + debugCodexNodes = false, + # requires CodexConfig.debug to be enabled in the test file (on the marketplacesuite) + debugHardhat = false, ) try: trace "starting test manager"