diff --git a/build.nims b/build.nims index 14ffeb7d..d17283eb 100644 --- a/build.nims +++ b/build.nims @@ -54,7 +54,8 @@ task testIntegration, "Run integration tests": var testParams = "" for i in 2 ..< paramCount(): if "DebugTestHarness" in paramStr(i) and truthy paramStr(i).split('=')[1]: - testParams = "-d:chronicles_log_level=TRACE -d:chronicles_sinks=textlines[stdout]" + testParams = + "-d:chronicles_log_level=TRACE -d:chronicles_sinks=textlines[dynamic],json[dynamic],textlines[dynamic]" break test "testIntegration", params = testParams # use params to enable logging from the integration test executable diff --git a/tests/integration/hardhatprocess.nim b/tests/integration/hardhatprocess.nim index bc52d780..c8e06835 100644 --- a/tests/integration/hardhatprocess.nim +++ b/tests/integration/hardhatprocess.nim @@ -77,8 +77,7 @@ method start*( let poptions = node.processOptions + {AsyncProcessOption.StdErrToStdOut} let args = @["node", "--export", "deployment-localhost.json"].concat(node.arguments) - trace "starting node", - args, executable, workingDir = node.workingDir, processOptions = poptions + trace "starting node", args, executable, workingDir = node.workingDir try: node.process = await startProcess( diff --git a/tests/integration/nodeprocess.nim b/tests/integration/nodeprocess.nim index 3257bbfc..e0a7413f 100644 --- a/tests/integration/nodeprocess.nim +++ b/tests/integration/nodeprocess.nim @@ -53,10 +53,7 @@ method start*(node: NodeProcess) {.base, async: (raises: [CancelledError]).} = let poptions = node.processOptions + {AsyncProcessOption.StdErrToStdOut} trace "starting node", - args = node.arguments, - executable = node.executable, - workingDir = node.workingDir, - processOptions = poptions + args = node.arguments, executable = node.executable, workingDir = node.workingDir try: if node.debug: diff --git a/tests/integration/testmanager.nim b/tests/integration/testmanager.nim index f938cdab..5e42f800 100644 --- a/tests/integration/testmanager.nim +++ b/tests/integration/testmanager.nim @@ -6,6 +6,7 @@ from std/unicode import toUpper import std/unittest import pkg/chronos import pkg/chronos/asyncproc +import pkg/codex/conf import pkg/codex/logutils import pkg/codex/utils/trackedfutures import pkg/questionable @@ -66,9 +67,6 @@ type IntegrationTest = ref object manager: TestManager config: IntegrationTestConfig - # process: Future[CommandExResponse].Raising( - # [AsyncProcessError, AsyncProcessTimeoutError, CancelledError] - # ) process: AsyncProcessRef timeStart: ?Moment timeEnd: ?Moment @@ -124,9 +122,19 @@ template ignoreCancelled(body) = except CancelledError: discard +func logFile*(_: type TestManager, dir: string): string = + dir / "TestHarness.log" + +func logFile(manager: TestManager): string = + TestManager.logFile(manager.logsDir) + +func logFile(test: IntegrationTest, fileName: string): string = + test.logsDir / fileName + proc new*( _: type TestManager, configs: seq[IntegrationTestConfig], + logsDir: string, debugTestHarness = false, debugHardhat = false, debugCodexNodes = false, @@ -144,6 +152,7 @@ proc new*( showContinuousStatusUpdates: showContinuousStatusUpdates, testTimeout: testTimeout, trackedFutures: TrackedFutures.new(), + logsDir: logsDir, ) func init*( @@ -409,8 +418,6 @@ proc teardownTest( Future[seq[byte]].Raising([CancelledError, AsyncStreamError]), ) {.async: (raises: []).} = test.timeEnd = some Moment.now() - if test.status == IntegrationTestStatus.Ok: - info "Test completed", name = test.config.name, duration = test.duration if not test.process.isNil: var output = test.output.expect("should have output value") @@ -426,6 +433,11 @@ proc teardownTest( output.stdOut = string.fromBytes(await noCancel stdOutStream) output.stdErr = string.fromBytes(await noCancel stdErrStream) test.output = success output + test.logFile("stdout.log").appendFile(output.stdOut.stripAnsi) + if test.status == IntegrationTestStatus.Error: + test.logFile("stderr.log").appendFile(output.stdErr.stripAnsi) + except IOError as e: + warn "Failed to write test stdout and stderr to file", error = e.msg except AsyncStreamError as e: test.timeEnd = some Moment.now() error "Failed to read test process output stream", error = e.msg @@ -595,6 +607,25 @@ proc run(test: IntegrationTest) {.async: (raises: []).} = printStdOut = test.status != IntegrationTestStatus.Ok, printStdErr = test.status == IntegrationTestStatus.Error, ) + logScope: + name = test.config.name + duration = test.duration + + case test.status + of IntegrationTestStatus.New: + raiseAssert "Test has completed, but is in the New state" + of IntegrationTestStatus.Running: + raiseAssert "Test has completed, but is in the Running state" + of IntegrationTestStatus.Error: + error "Test errored", + error = test.output.errorOption .? msg, + stack = test.output.errorOption .? getStackTrace() + of IntegrationTestStatus.Failed: + error "Test failed" + of IntegrationTestStatus.Timeout: + error "Test timed out" + of IntegrationTestStatus.Ok: + notice "Test passed" proc runTests(manager: TestManager) {.async: (raises: [CancelledError]).} = var testFutures: seq[Future[void]] @@ -603,6 +634,7 @@ proc runTests(manager: TestManager) {.async: (raises: [CancelledError]).} = echoStyled styleBright, bgWhite, fgBlack, "\n[Integration Test Manager] Starting parallel integration tests" + notice "[Integration Test Manager] Starting parallel integration tests" for config in manager.configs: var test = @@ -685,35 +717,14 @@ proc printResult(manager: TestManager) {.raises: [TestManagerError].} = resetStyle, " |" echo "▢=====================================================================▢" + notice "INTEGRATION TEST SUMMARY", + totalTime = manager.duration, + timeSavedEst = &"{relativeTimeSaved}%", + passing = &"{successes} / {manager.tests.len}" proc start*( manager: TestManager ) {.async: (raises: [CancelledError, TestManagerError]).} = - try: - if manager.debugCodexNodes: - let startTime = now().format("yyyy-MM-dd'_'HH:mm:ss") - let logsDir = - currentSourcePath.parentDir() / "logs" / - sanitize(startTime & "__IntegrationTests") - createDir(logsDir) - manager.logsDir = logsDir - #!fmt: off - echoStyled bgWhite, fgBlack, styleBright, - "\n\n ", - styleUnderscore, - "ℹ️ LOGS AVAILABLE ℹ️\n\n", - resetStyle, bgWhite, fgBlack, styleBright, - """ Logs for this run will be available at:""", - resetStyle, bgWhite, fgBlack, - &"\n\n {logsDir}\n\n", - resetStyle, bgWhite, fgBlack, styleBright, - " NOTE: For CI runs, logs will be attached as artefacts\n" - #!fmt: on - except IOError as e: - raiseTestManagerError "failed to create hardhat log directory: " & e.msg, e - except OSError as e: - raiseTestManagerError "failed to create hardhat log directory: " & e.msg, e - if manager.showContinuousStatusUpdates: let fut = manager.continuallyShowUpdates() manager.trackedFutures.track fut @@ -748,4 +759,3 @@ proc stop*(manager: TestManager) {.async: (raises: []).} = trace "Terminated running hardhat process" except CatchableError as e: trace "failed to stop hardhat node", error = e.msg - diff --git a/tests/integration/utils.nim b/tests/integration/utils.nim index bcdff4ed..4ce8fcda 100644 --- a/tests/integration/utils.nim +++ b/tests/integration/utils.nim @@ -51,3 +51,16 @@ proc getLogFile*( let fileName = logsDir / fn return fileName + +proc appendFile*(filename: string, content: string) {.raises: [IOError].} = + ## Opens a file named `filename` for writing. Then writes the + ## `content` completely to the file and closes the file afterwards. + ## Raises an IO exception in case of an error. + var f: File + try: + f = open(filename, fmAppend) + f.write(content) + except IOError as e: + raise newException(IOError, "cannot open and write " & filename & ": " & e.msg) + finally: + close(f) diff --git a/tests/testIntegration.nim b/tests/testIntegration.nim index 89b9a217..49b0f3a9 100644 --- a/tests/testIntegration.nim +++ b/tests/testIntegration.nim @@ -34,14 +34,72 @@ const DebugCodexNodes {.booldefine.} = false # Shows test status updates at time intervals. Useful for running locally with # active terminal interaction. Set to false for unattended runs, eg CI. const ShowContinuousStatusUpdates {.booldefine.} = false -# Timeout duration (in mimutes) for EACH integration test file. +# Timeout duration (in minutes) for EACH integration test file. const TestTimeout {.intdefine.} = 60 const EnableParallelTests {.booldefine.} = true +proc setupLogging(logFile: string, debugTestHarness: bool) = + when defaultChroniclesStream.outputs.type.arity != 3: + raiseAssert "Logging configuration options not enabled in the current build" + else: + proc writeAndFlush(f: File, msg: LogOutputStr) = + try: + f.write(msg) + f.flushFile() + except IOError as err: + logLoggingFailure(cstring(msg), err) + + proc noOutput(logLevel: LogLevel, msg: LogOutputStr) = + discard + + proc stdoutFlush(logLevel: LogLevel, msg: LogOutputStr) = + writeAndFlush(stdout, msg) + + proc fileFlush(logLevel: LogLevel, msg: LogOutputStr) = + try: + logFile.appendFile(stripAnsi(msg)) + except IOError as error: + fatal "Failed to write to log file", error = error.msg # error = error.ioErrorMsg + raiseAssert "Could not write to test manager log file: " & error.msg + + defaultChroniclesStream.outputs[0].writer = stdoutFlush + defaultChroniclesStream.outputs[1].writer = noOutput + if debugTestHarness: + defaultChroniclesStream.outputs[2].writer = fileFlush + else: + defaultChroniclesStream.outputs[2].writer = noOutput + proc run(): Future[bool] {.async: (raises: []).} = + let startTime = now().format("yyyy-MM-dd'_'HH:mm:ss") + let logsDir = + currentSourcePath.parentDir() / "integration" / "logs" / + sanitize(startTime & "__IntegrationTests") + try: + if DebugTestHarness or DebugHardhat or DebugCodexNodes: + createDir(logsDir) + #!fmt: off + styledEcho bgWhite, fgBlack, styleBright, + "\n\n ", + styleUnderscore, + "ℹ️ LOGS AVAILABLE ℹ️\n\n", + resetStyle, bgWhite, fgBlack, styleBright, + """ Logs for this run will be available at:""", + resetStyle, bgWhite, fgBlack, + &"\n\n {logsDir}\n\n", + resetStyle, bgWhite, fgBlack, styleBright, + " NOTE: For CI runs, logs will be attached as artefacts\n" + #!fmt: on + except IOError as e: + raiseAssert "Failed to create log directory and echo log message: " & e.msg + except OSError as e: + raiseAssert "Failed to create log directory and echo log message: " & e.msg + + setupLogging(TestManager.logFile(logsDir), DebugTestHarness) + let manager = TestManager.new( configs = TestConfigs, + logsDir, DebugTestHarness, DebugHardhat, DebugCodexNodes,