Discussion on Pester Output

[Chris Hunt]

All:

I recently forked Pester (https://github.com/cdhunt/Pester) and replaced the instances of Write-Host. I was trying to update the module to follow Powershell best practices and provide some more control of output.

Here is a summary of the functional changes.

Invoke-Pester with no parameters will show a progress bar that includes a count of failed tests, if any, when encountered. No output will be written to the shell if all tests pass. No news is good news.

Invoke-Pester -Verbose will write the same messages currently displayed via Write-Host, but to the Verbose stream.

VERBOSE: [+]   should write a failed test result 65ms
VERBOSE: [+]   should write the test summary 65ms
VERBOSE: [+]   should write the test-suite information 66ms
VERBOSE: [+]   should write two test-suite elements for two describes 71ms
VERBOSE: [+]   should write the environment information 66ms
VERBOSE: [+]   Should validate test results against the nunit 2.5 schema 71ms
VERBOSE: Tests completed in 950ms
VERBOSE: Passed: 132 Failed: 0

Invoke-Pester -PassThru will output the $pester.testResults hashtable to the pipeline which you can save to a variable and examine for any or all details of the test results. Another person (https://github.com/nohwnd) is also working on improving the output object to be flatter and easier to work with in the shell.

Regardless of output parameter, any failed tests will write a message to the Warning stream.

WARNING: [-]   does not pollute the global namespace 7ms
WARNING:   Expected: value to be empty but it was {globalGarbage}
WARNING:   at line: 32 in C:\GitHub\Pester\Functions\It.Tests.ps1

This provide a good amount of control over the output. The drawback to this approach is the loss of colored output which I gather some people are quite partial too. Personally, I think this is still an improvement since by default it only outputs failures to the screen; it is very clear when test fail without scrolling through hundreds of lines of output.

I'm interested to hear everyone's opinion.

Thanks,

-- Chris

[Scott Muc]

I'm cool with it. I think it'll bump the version of Pester because it's somewhat API breaking. Pester is due for a new release, and I don't mind if there are breaking API changes. 

Whenever I run rspec, the commands look like:

rspec *_spec.rb --format documentation --color

I would be ok if it becomes: Invoke-Pester .\tests -verbose -color

but I've also thought about:

Invoke-Pester .\tests | Format-PesterDots -Color

Invoke-Pester .\tests | Format-PesterDocumentation -Color

and some way to output current progress so you don't have to wait til the end (although, I think the pipelining should be able to do that, right?)

Having the failing tests displayed at the end is something I've wanted for a while, but have never had a large enough test suite for it to have been a problem :-)

I'm interested in what nohwnd has to say as well. This functionality isn't something that I've been needing so I don't really have strong opinions on it. As long as it doesn't make the code more complex, I'm happy.

Scott

--
You received this message because you are subscribed to the Google Groups "Pester" group.
To unsubscribe from this group and stop receiving emails from it, send an email to pester+un...@googlegroups.com.
For more options, visit https://groups.google.com/groups/opt_out.

[Chris Hunt]

The changes I made don't alter any of the existing functionality. I ran build.psake.ps1 and it worked the same as previously. In automated testing, the output is pointless anyway.

I also then updated the build script to use PassThru to get the global test results instead of using EnableExit and calling an external Batch file.

Task Test {
    CD "$baseDir"
    $testResults = Invoke-Pester -PassThru
    if ($testResults.FailedTestsCount -ne 0)
    {
        Throw "Unit Tests Failed"
    }
    CD $currentDir
}

These aren't necessary changes, they just make the output consistent with other modules. Most of the new cmdlets in Posh 4 don't output anything unless the -verbose flag is set or there is an error.

[Matt Wrock]

I definitely agree with getting away from Write-Host at least as a default. The problem I see with -verbose is that you lose the color. The verbose stream outputs everything in yellow. I personally find having all failed tests output in red very helpful. Especially if I am in a TDD workflow and I have alot of tests, I can quickly see the red and may ctrl+c to stop the test and work to get the test green.

I like the idea of using a Formatter. This could preserve the color and maintains best practices. I also think having the option to print the failed tests at the end is a great idea. My Boxstarter project has almost 300 tests and I'll run all of them when getting ready to do a deployment. Its getting to the point where all the test output surpasses my console's buffer if there are many exceptions.

To me, the ideal output would be to have each test be returned as a PSObject to the pipeline that includes a property that holds the exceptions and maybe also a property that is a Hashtable of all variables in the Variable PSDrive. This way I could examine error details like inner exceptions and detailed stack traces as well as state of a failed test. This with a formatter for coloring would be awesome. 

[Chris Hunt]

So, as I have written it, failed tests will always go to the Warning stream which is always displayed (in the same yellow, but in real-time). So, just plain Invoke-Pester will essentially produce a summary of failed tests and the Verbose flag is truly to enable full verbose output.

I looked at the type formatter used in the Get-WindowsFeature cmdlet that produces similar indented format to Pester. That would be relatively simple to implement if the test results are written to the pipeline as a PSCustomObject instead of stored aggregate in a hashtable.

Matt, I think you'd find the changes I made very helpful when running 300 tests even without colored output, and I fully agree about the ideal output as the next milestone.

[Johan Leino]

For me, the thing that sometimes annoys me with Pester is that it uses Write-Host the way it does. 

I sometimes haves tests where I would like to Mock WH to prove something. If I do that, Pester doesn't output anything.

So regarding WH and the Pester output I think you're on to something good here and maybe Pester could go down the same route as chocolatey has gone with it's own WH.ps1 which wraps WH and logs to file before sending it down the pipeline. However, choco still lacks the option to turn off WH completely...but it's on its way I think.

Anyway, the more configurable Pester gets, the better for us!

/ J

[Scott Muc]

So... I think everyone agrees that WH in PowerShell code is bad. Just like system.println, puts, echo, etc...

Writing to a console is a system boundary, just like a DB, SOA endpoint, disk. For an excellent talk on boundaries, I highly recommend this one: https://www.destroyallsoftware.com/talks/boundaries

Things that have worked well for me with this problem is introducing thin service abstractions.

Right now, Pester looks like this with regard to Write-Host abstractions:

Pester Core -> Write-Host

Here's an alternative

Pester Core -> Logger -> WriteHostLogger

                                        -> QuietConsoleLogger

                                        -> FileLogger

                                        -> NUnitXmlLogger

This thin layer is going to be internal to Pester, so I don't think it's important to follow the verb-noun convention. If the TDD drives it in such a way, that's fine.

Also, I don't really want Pester to have a crazily engineered logging framework built in. I'm happy with the simple abstraction, and a simple loggers built into Pester (to keep it dependency free)

Scott

--

[Chris Hunt]

So, replace the call to Write-PesterResult in It  with a call to a new Logger function. The Logger function simply contains condition logic that calls one or more of the output functions you defined.

Does that align with your thoughts?

[Scott Muc]

I think so. Coupling to Write-Verbose is a boundary as well, and would like to get that encapsulated in a Logger.

Scott

[Chris Hunt]

I think using a Custom Type Format file is the way to go for writing human readable text to the screen. The indenting and [+] and [-] strings are easy to manage, but I can't find any reference to manipulating output color through these files.

I took an initial stab at the abstraction that mostly supports the Write-Host functionality, but it still needs a lot of work to clean up all of the instances of Write-Host. There's not really a point in building a Format file if Write-Host is used and not much point using Write-Host if a Format file is used. Is color coding the messages a requirement? If so, I don't see any option but to use Write-Host.

https://github.com/cdhunt/Pester/commit/c829c9aeee1e4cac7eb754ff22bc1c282ecdb5bf

[Scott Muc]

To me, colour output is a must have. Colour coding in the terminal, text editor, console app output is a big part of user experience.

Alrighty... I'm off for 10 days (going to Tanzania to climb Kilimanjaro) :-D

[Matt Wrock]

Kilimanjaro  Very cool. Enjoy!