Piping into Select -First is exhibiting unexpected behavior when piping into Should

[theficus]

I feel like I'm just doing something stupid here but this seems like it should work. I have been unable to get a standalone repro and it only reproduces when using a specific set of cmdlets -- I don't know why, though.

Here's the situation I'm observing:

Cmdlet Get-XXX return n results, I want to verify at least one result is returned so I execute something like this:

Describe "PesterTest" {
  It "Get-XXX Test" {
    Get-XXX | Select -First 1 | Should Not BeNullOrEmpty
  }
}

What will happen when I run this in PowerShell is this:

Describing PesterTest

Note that it terminates execution somewhere before completing.

Now, to make things even stranger, if I wrap the code into a Context { }:

Describe "PesterTest" {
  Context "Uber Context" {
    It "Get-XXX Test" {
      Get-XXX | Select -First 1 | Should Not BeNullOrEmpty
    }
  }
}

This happens when executing:

Describing PesterTest
   Context Uber Context
    [-] Error occurred in Describe block 474ms
      Exception calling "LeaveContext" with "0" argument(s): "Cannot leave Context before leaving It"
      At PesterTest.Tests.ps1:17 char:5
Exception calling "LeaveDescribe" with "0" argument(s): "Cannot leave Describe before leaving Context"
At C:\Modules\Pester\Functions\Describe.ps1:117 char:5
+     $Pester.LeaveDescribe()
+     ~~~~~~~~~~~~~~~~~~~~~~~
    + CategoryInfo          : NotSpecified: (:) [], MethodInvocationException
    + FullyQualifiedErrorId : ScriptMethodRuntimeException

Even stranger yet, if I do something like this:

Get-XXX | Select -First 1 | Should BeNullOrEmpty

.. will cause the test to pass, even though Get-XXX has returned a value.

For some bizarre reason the cmdlets I'm calling seem to have some weird interoperability quirk that causes this to occur.

Stranger yet, if I don't pipe into Select, the assertions seem to work as expected.

I've tried to debug into each condition and I'm not quite sure what's happening.

Here's what I've observed in the first scenario ("Get-XXX | Select -First 1 | Should Not BeNullOrEmpty" without using Context { }):

• When in Should.ps end { }, $value is set to the value I would expect (the output of Get-XXX). ParsedArgs looks like this:

Name                           Value                                                                                                                                                                                                                             
----                           -----                                                                                                                                                                                                                             
PositiveAssertion              False                                                                                                                                                                                                                             
ExpectedValue                                                                                                                                                                                                                                                    
AssertionMethod                PesterBeNullOrEmpty 

After Get-TestResult, $testFailed is set to $false as expected. After Should goes out of scope, ItImpl tears down. I don't know why.

Here's what I've observed in the secindscenario ("Get-XXX | Select -First 1 | Should Not BeNullOrEmpty" with using Context { }): Same $shouldArgs as before, and $value is set as expected in Get-TestResult $testResult is false as expected Invoke-TestGroupTeardownBlocks -Scope $pester.Scope is called after Should goes out of scope. Again, I don't know why.

Third scenario, "Get-XXX | Select -First 1 | Should BeNullOrEmpty" which I would expect to fail (not using Context { } for simplicity):

Get-TestResult $value is set as expected. $shouldArgs is:

Name                           Value                                                                                                                                                                                                                             
----                           -----                                                                                                                                                                                                                             
PositiveAssertion              True                                                                                                                                                                                                                              
ExpectedValue                                                                                                                                                                                                                                                    
AssertionMethod                PesterBeNullOrEmpty    

PesterBeNullOrEmpty returns false, as expected since $value is not null (the object I'm passing to this function has a 'Count' property but it is 1, so it goes to the $value.Count -lt 1 and returns false from there. $testResult ultimately returns false, but because PositiveAssertion is True, it gets flipped and returns true. The "throw" gets called and, gets swallowed somewhere? I'm not really sure at this point what is happening.

I am not able to reproduce the issue when doing something like this:

$o = New-Object PsObject
$o | Add-Member "Name" "Test Name 1"
$o | Add-Member "Count" 1

$p = New-Object PsObject
$p | Add-Member "Name" "Test Name 2"
$p | Add-Member "Count" 1

$items = ($o, $p)

Describe -Tag "P1" "PesterTest" {
    #Context "Uber Context" {
        It "Get-XXX Test" {
          $items | Select -First 1 | Should BeNullOrEmpty          
        }
    #}
}

So it seems to be something strange specific to the objects I'm passing.

Just for a bit of extra information the objects I'm passing have a custom PS type provider -- perhaps there's some strange interaction going on there that's causing issues?

Any ideas here would be appreciated. I hope this report makes sense.

[dlwyatt]

What versions of PowerShell and Pester are you using? I ran your code with a simple function for Get-XXX and it worked fine (on the latest PowerShell 5.0 preview, and the latest version of Pester.)

[theficus]

Yes, it's quite strange and I'm pretty sure it's due to the type of objects I'm passing (these aren't standard PS Framework objects, they are from the custom type provider I'm working with). I updated the issue details with some more information as well but I'm a bit stumped as to where to begin looking.

I'm using the latest version of Pester (just did a pull this morning) and PowerShell 4.0.

[dlwyatt]

OK, I'll see if I can reproduce it on PowerShell 4.0. Does this only happen with your Get-XXX cmdlet, or can you reproduce it with other code as well?

[theficus]

It happens only with Get-XXX cmdlets (I'm running cmdlets from a cmdlet library that I maintain) that use the custom type provider. I'm still stepping through the Pester code trying to get a handle on what exactly is going on to cause this to fail.

In case 3 at least, the best I can tell at this time the:

throw ( New-ShouldErrorRecord -Message $failureMessage -Line $line -LineText $lineText)

statement gets called as expected in Should.ps1 but then gets swallowed somewhere down the line and so far I have no idea why this is happening.

[dlwyatt]

That may be a problem. I need a way to reproduce the bug if I'm going to be able to help with troubleshooting and fix it. Can I download a copy of your module for testing? If so, you can email me a link at dlwyatt115@gmail.com .

[theficus]

Unfortunately I am unable to do this as it is a framework that is specific to a product I develop, and it has dependencies on that product to even get it going. Yeah, I know, this makes it a million times more difficult to troubleshoot which is why I tried to be so detailed in my repro steps. As I can reproduce this pretty easily if you have any thoughts on where I should look I would be happy to start poking around. I will also see if I can put together some kind of standalone repro for this.

[dlwyatt]

Out of curiosity, does this happen if you split it into two commands?

  It "Get-XXX Test" {
    $result = Get-XXX | Select -First 1
    $result | Should Not BeNullOrEmpty
  }

If that works, it at least gets you a workaround for the time being.

Beyond that, I'm really not sure what's going on. I know that (since PowerShell 3.0), Select-Object -First works by throwing an exception in the PowerShell engine to abort the pipeline when the required number of objects have passed through. This exception doesn't normally cause any trouble for the upstream cmdlets (and should not affect the PowerShell code that's running), but maybe you've found some way of triggering a bug from your cmdlet.

[theficus]

That's absolutely fascinating. When I change the code to be like this:

        It "Get-XXX Test" {
            $result = Get-XXX | Select -First 1
            $result | Should BeNullOrEmpty
        }

The "Should" call literally never happens -- I'm assuming at this point that the Pester code is getting very confused which is why it behaves so inconsistently at this point. I guess it's either a bug in PowerShell itself, or a bug in my cmdlet library. I will investigate further.

Since this doesn't appear to be a Pester issue at this time, I'm going to close this out.

Thanks for the super quick assistance.

[dlwyatt]

Try this, taking Pester out of the picture for the moment:

function Test-Weirdness
{
    Write-Host 'Before'
    try
    {
        $result = Get-XXX | Select-Object -First 1
        Write-Host 'After'
    }
    finally
    {
        Write-Host 'Finally'
    }

    Write-Host 'After Finally'
}

Test-Weirdness

See which of those Write-Host messages wind up on your screen. Normally, all of them should be output.

[theficus]

What I see is "Before", the output of Get-XXX, and "Finally". No "After" or "After-Finally".

Yup, definitely not a Pester issue. :)

[dlwyatt]

Hmm... so it's behaving like a terminating exception is being thrown, but not actually giving you any error output. Very weird. Let's add one tweak to see if you can get any information about it from inside PowerShell:

function Test-Weirdness
{
    Write-Host 'Before'
    try
    {
        $result = Get-XXX | Select-Object -First 1
        Write-Host 'After'
    }
    catch
    {
        $_ | Format-List * -Force | Out-Host
    }
    finally
    {
        Write-Host 'Finally'
    }

    Write-Host 'After Finally'
}

Test-Weirdness

If not, then maybe you just need to fire up Visual Studio and attach a debugger to your process. You can probably start with your Get-XXX cmdlet's BeginProcessing() method, and step through from there.

[theficus]

Good news, I finally figured out what the isuse was.

It looks like my cmdlet code was swallowing PipelineStoppedException (it was actually doing this for a good reason, but it was being too aggressive about it). Normally this wouldn't present a problem but in this case Select -First n was trying to stop the pipeline and this was causing all kinds of strangeness when this exception wasn't bubbling up through the PowerShell framework since my code was swallowing it.

After fixing my code so that PipelineStoppedException would only be swallowed under a very tightly scoped set of conditions, it looks like things are now working as they should!

So while this ultimately wasn't a Pester issue at least Pester helped to raise this problem as part of unit testing the cmdlet code. :)