rmbolger/Posh-ACME.Deploy

New-ItemProperty and Set-IISCertificate remote script issue

mclacore opened this issue · 8 comments

I'm trying to create a function app to run a script remotely. The script on the web server creates a new certificate, validates it, and then creates the binding in IIS to the server's site. I have run the script remotely before by using Invoke-AzVMRunCommand without any issues. Now I'm building a function app in Azure to run the script, using the same Invoke-AzVMRunCommand, but I'm seeing the following errors that we can't figure out:

2021-06-28T16:20:12.834 [Information] OUTPUT: Value[0]        :
2021-06-28T16:20:12.835 [Information] OUTPUT:   Code          : ComponentStatus/StdOut/succeeded
2021-06-28T16:20:12.835 [Information] OUTPUT:   Level         : Info
2021-06-28T16:20:12.835 [Information] OUTPUT:   DisplayStatus : Provisioning succeeded
2021-06-28T16:20:12.835 [Information] OUTPUT:   Message       : MainDomain            status KeyLength SANs OCSPMustStaple CertExpires Plugin
2021-06-28T16:20:12.835 [Information] OUTPUT: ----------            ------ --------- ---- -------------- ----------- ------
2021-06-28T16:20:12.835 [Information] OUTPUT: staging5.xdemo2.com ready  2048      {}   False                      {Manual}
2021-06-28T16:20:12.836 [Information] OUTPUT:
2021-06-28T16:20:12.836 [Information] OUTPUT: LastWriteTime : 6/28/2021 11:19:34 AM
2021-06-28T16:20:12.836 [Information] OUTPUT: Length        : 87
2021-06-28T16:20:12.836 [Information] OUTPUT: Name          : x
2021-06-28T16:20:12.836 [Information] OUTPUT:
2021-06-28T16:20:12.836 [Information] OUTPUT:
2021-06-28T16:20:12.838 [Information] OUTPUT: Subject       : CN=staging5.xdemo2.com
2021-06-28T16:20:12.838 [Information] OUTPUT: NotBefore     : 6/28/2021 10:19:36 AM
2021-06-28T16:20:12.839 [Information] OUTPUT: NotAfter      : 9/26/2021 10:19:35 AM
2021-06-28T16:20:12.839 [Information] OUTPUT: KeyLength     : 2048
2021-06-28T16:20:12.839 [Information] OUTPUT: Thumbprint    : x
2021-06-28T16:20:12.839 [Information] OUTPUT: AllSANs       : {staging5.xdemo2.com}
2021-06-28T16:20:12.840 [Information] OUTPUT: CertFile      : C:\Posh-Acme\acme-staging-v02.api.letsencrypt.org\20039939\stag
2021-06-28T16:20:12.840 [Information] OUTPUT:                 ing5.xdemo2.com\cert.cer
2021-06-28T16:20:12.840 [Information] OUTPUT: KeyFile       : C:\Posh-Acme\acme-staging-v02.api.letsencrypt.org\20039939\stag
2021-06-28T16:20:12.840 [Information] OUTPUT:                 ing5.xdemo2.com\cert.key
2021-06-28T16:20:12.840 [Information] OUTPUT: ChainFile     : C:\Posh-Acme\acme-staging-v02.api.letsencrypt.org\20039939\stag
2021-06-28T16:20:12.840 [Information] OUTPUT:                 ing5.xdemo2.com\chain.cer
2021-06-28T16:20:12.840 [Information] OUTPUT: FullChainFile : C:\Posh-Acme\acme-staging-v02.api.letsencrypt.org\20039939\stag
2021-06-28T16:20:12.841 [Information] OUTPUT:                 ing5.xdemo2.com\fullchain.cer
2021-06-28T16:20:12.841 [Information] OUTPUT: PfxFile       : C:\Posh-Acme\acme-staging-v02.api.letsencrypt.org\20039939\stag
2021-06-28T16:20:12.841 [Information] OUTPUT:                 ing5.xdemo2.com\cert.pfx
2021-06-28T16:20:12.841 [Information] OUTPUT: PfxFullChain  : C:\Posh-Acme\acme-staging-v02.api.letsencrypt.org\20039939\stag
2021-06-28T16:20:12.841 [Information] OUTPUT:                 ing5.xdemo2.com\fullchain.pfx
2021-06-28T16:20:12.841 [Information] OUTPUT: PfxPass       : System.Security.SecureString
2021-06-28T16:20:12.841 [Information] OUTPUT:
2021-06-28T16:20:12.842 [Information] OUTPUT:
2021-06-28T16:20:12.842 [Information] OUTPUT:
2021-06-28T16:20:12.847 [Information] OUTPUT: Value[1]        :
2021-06-28T16:20:12.848 [Information] OUTPUT:   Code          : ComponentStatus/StdErr/succeeded
2021-06-28T16:20:12.848 [Information] OUTPUT:   Level         : Info
2021-06-28T16:20:12.848 [Information] OUTPUT:   DisplayStatus : Provisioning succeeded
2021-06-28T16:20:12.848 [Information] OUTPUT:   Message       : New-ItemProperty : Property Bindings is not found on  \\S-STG-WEB-1\Sites.
2021-06-28T16:20:12.849 [Information] OUTPUT: Parameter name: propName
2021-06-28T16:20:12.849 [Information] OUTPUT: At C:\Program Files\WindowsPowerShell\Modules\Posh-ACME.Deploy\1.2.0\Public\Set
2021-06-28T16:20:12.849 [Information] OUTPUT: -IISCertificate.ps1:98 char:13
2021-06-28T16:20:12.849 [Information] OUTPUT: +             New-ItemProperty $sitePath -Name Bindings -Value $bindPro ...
2021-06-28T16:20:12.849 [Information] OUTPUT: +             ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
2021-06-28T16:20:12.850 [Information] OUTPUT:     + CategoryInfo          : InvalidArgument: (:) [New-ItemProperty], Argumen
2021-06-28T16:20:12.850 [Information] OUTPUT:    tException
2021-06-28T16:20:12.850 [Information] OUTPUT:     + FullyQualifiedErrorId : InvalidArgument,Microsoft.PowerShell.Commands.Ne
2021-06-28T16:20:12.850 [Information] OUTPUT:    wItemPropertyCommand
2021-06-28T16:20:12.850 [Information] OUTPUT:
2021-06-28T16:20:12.850 [Information] OUTPUT: New-Item : Cannot create a file when that file already exists
2021-06-28T16:20:12.850 [Information] OUTPUT: At C:\Program Files\WindowsPowerShell\Modules\Posh-ACME.Deploy\1.2.0\Public\Set
2021-06-28T16:20:12.850 [Information] OUTPUT: -IISCertificate.ps1:159 char:25
2021-06-28T16:20:12.851 [Information] OUTPUT: + ...     $cert | New-Item IIS:\SslBindings\$sslMatch -SslFlags $sslFlags | ...
2021-06-28T16:20:12.851 [Information] OUTPUT: +                 ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
2021-06-28T16:20:12.851 [Information] OUTPUT:     + CategoryInfo          : NotSpecified: (:) [New-Item], Win32Exception
2021-06-28T16:20:12.851 [Information] OUTPUT:     + FullyQualifiedErrorId : System.ComponentModel.Win32Exception,Microsoft.P
2021-06-28T16:20:12.851 [Information] OUTPUT:    owerShell.Commands.NewItemCommand
2021-06-28T16:20:12.851 [Information] OUTPUT:
2021-06-28T16:20:12.851 [Information] OUTPUT: Status          : Succeeded
2021-06-28T16:20:12.851 [Information] OUTPUT: Capacity        : 0
2021-06-28T16:20:12.852 [Information] OUTPUT: Count           : 0
2021-06-28T16:20:12.852 [Information] OUTPUT:
2021-06-28T16:20:13.680 [Information] OUTPUT: Finished Invoke-AzVMRunCommand
2021-06-28T16:20:13.719 [Information] OUTPUT:
2021-06-28T16:20:13.873 [Information] Executed 'Functions.Add-Host-SSL' (Succeeded, Duration=117379ms)

I'm calling which server to contact with based on IP address and server name. Tried using both external and internal IP addresses.

We can confirm it creates the web certificates on the web server, it's just having an issue binding them.

Hey @mclacore, sorry for the trouble. The error messages make it seem like the problem revolves around the Bindings property on $site object...that a Bindings property doesn't exist...which I didn't think was possible. Like, even if a site has no bindings, I would think at least an empty Bindings property would still exist. But let me see if I can reproduce it on a VM of my own and figure something out.

So my initial attempts to repro this were stymied a bit on the 2016 VM I had immediately available. IIS and PowerShell won't even let me create a site without at least one binding. What OS is the VM running that you're having the trouble with? I just want to make sure I'm trying to test things as close to your config as possible.

It also seems weird that things have worked previously outside of Azure Functions, but don't while using the same Invoke-AzVMRunCommand from a function. Is it possible, you're running into some sort of a race condition with the VM not actually being ready yet? I'm afraid I have basically zero experience with Azure Functions. So I'm not sure how much help I'm going to be.

@rmbolger we are running Windows Server 2016 DC

Yea I'm not sure about the race condition. Have you seen that powershell error before? I'll paste the script we're using server side to create the cert, validate, and add the binding. As I've said before, this script works perfect when run locally and when run remotely via PS console, just not through the Function App:

Param(
	[string]$HostName,
        [string]$IISSite
)
#POSH ACME Environment Settings
$HomePath = "C:\Posh-Acme"
If(!(test-path $HomePath)) {
      New-Item -ItemType Directory -Force -Path $HomePath
}
$env:POSHACME_HOME = $HomePath

$LE_SERVER = "LE_Stage"
$ContactEmail = "email@domain.com"
$Path = "E:\websites\domain\generation2"
$pArgs = @{ WRPath = $Path }
$certPass = "password"
Set-PAServer $LE_SERVER
$Account = Get-PAAccount
    if (($Account.status) -eq "valid") {
        
        Set-PAAccount -Contact $ContactEmail
    }
    else {
        
        New-PAAccount -AcceptTOS -Contact $ContactEmail
    } 

New-PAOrder $HostName -Force
$Authorization = Get-PAOrder | Get-PAAuthorization
$ChallengeToken  = $Authorization.HTTP01Token
$toPublish = $Authorization | Select @{L='Url';E={"http://$($_.fqdn)/.well-known/acme-challenge/$($_.HTTP01Token)"}}, `
                                         @{L='Body';E={Get-KeyAuthorization $_.HTTP01Token (Get-PAAccount)}}
New-Item -Path "$Path\.well-known\acme-challenge" -Name $Authorization.HTTP01Token -ItemType "file" -Value $toPublish.Body -Force
$Authorization.HTTP01Url | Send-ChallengeAck
New-PACertificate -Domain $HostName -AcceptTOS -Contact $ContactEmail -Plugin WebRoot -PluginArgs $pArgs -PfxPass $CertPass -force 
#(Get-PAOrder | Get-PAAuthorization).challenges.error | fl


Get-PACertificate | Set-IISCertificate -HostHeader $HostName -RequireSNI -SiteName $IISSite -RemoveOldCert

Set-PAOrder $HostName

$IISSite is set by the script running via the Function App. Here's that script we use to run the command:

using namespace System.Net

# Input bindings are passed in via param block.
param($Request, $TriggerMetadata)

# Set local variables
$Subscription = "azure sub name"

#Sets Current Subscription
Set-AzContext $Subscription | Out-Null
if($?) {
    Write-Host "[Azure] Successfully set subscription to $Subscription"
    $Body = $Body + "[Azure] Successfully set subscription to $Subscription `r`n"
    }
else {
    Write-Host "[Azure] Could not set subscription to $Subscription"
    $Body = $Body + "[Azure] Could not set subscription to $Subscription `r`n"
    $ErrorCount++
}

Write-Output "Loading Posh-ACME Module"
import-module 'D:\Home\site\wwwroot\script\Modules\Posh-ACME\4.5.0\Posh-ACME.psd1'

Write-Output "Loading Posh-ACME.Deploy Module"
import-module 'D:\Home\site\wwwroot\script\Modules\Posh-ACME.Deploy\1.2.0\Posh-ACME.Deploy.psd1'

# Interact with query parameters or the body of the request.
$WebURL = $Request.Params.WebURL
$IP = $Request.Params.IP

if ($IP = x.x.x.x) {
    $ServerName = 'server name'
    $IISSiteName = 'domain.com'
}

Write-Output "Running Invoke-AzVMRunCommand"

Invoke-AzVMRunCommand `
    -ResourceGroupName 'RG'`
    -Name $ServerName `
    -CommandId 'RunPowerShellScript' `
    -ScriptPath 'D:\Home\site\wwwroot\script\Scripts\Add-Host-SSL-PSN.ps1' `
    -Parameter @{"HostName" = $WebURL;"IISSite" = $IISSiteName}

Write-Output "Finished Invoke-AzVMRunCommand"

# Associate values to output bindings by calling 'Push-OutputBinding'.
Push-OutputBinding -Name Response -Value ([HttpResponseContext]@{
    StatusCode = [HttpStatusCode]::OK
    Body = $body
})

Have you seen that powershell error before?

I haven't, unfortunately. But it seems like a pretty straightforward error. The New-ItemProperty command is failing because it can't find the Bindings property on the site object. You can force a similar error manually by using an obviously bad property name on an existing site:

PS C:\Users\Administrator> New-ItemProperty $sitePath -Name asdfasdf -Value $bindProps
New-ItemProperty : Property asdfasdf is not found on  \\WIN2016WEB\Sites\MySite.example.com.
Parameter name: propName
At line:1 char:1
+ New-ItemProperty $sitePath -Name asdfasdf -Value $bindProps
+ ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
    + CategoryInfo          : InvalidArgument: (:) [New-ItemProperty], ArgumentException
    + FullyQualifiedErrorId : InvalidArgument,Microsoft.PowerShell.Commands.NewItemPropertyCommand

I just don't get why sometimes the Bindings property wouldn't exist. I'm also chalking up the second error as a symptom of the first error. Like, if we fix the root cause of the first error, the second error will go away as well.

I also don't see any obvious problems with the scripts you're using, btw. Everything they're doing looks good. Just to confirm though, the $Request.Params.WebURL in the second code block is just a hostname, right? Not an actual URL with the https:// prefix attached? I have to believe it is, because if it wasn't the cert request would've failed as well.

Just to confirm though, the $Request.Params.WebURL in the second code block is just a hostname, right? Not an actual URL with the https:// prefix attached? I have to believe it is, because if it wasn't the cert request would've failed as well.

Correct, I wanted to come up with a different variable because $HostName is used in the other script and I was afraid of a variable conflict.

Hey @mclacore, I just pushed a new version of Set-IISCertificate.ps1 to the main branch. It relies less on the IIS: provider which I've been reading has always been somewhat problematic. In particular for this issue though is that it now uses New-WebBinding and Set-WebBinding instead of New-ItemProperty and Set-ItemProperty. I'm hoping that will fix your issue or at least give us more info as to what might be wrong.

Can you give it a try?

I'm also attempting to build a version of the function that relies on the newer IISAdministration module rather than the older WebAdministration one. But if it works, it will depend on the version 1.1.0.0 of the module which needs to be installed from PowerShellGallery. Out of curiosity, would that be a problem in your environment?

Fyi, Set-IISCertificateNew.ps1 is also now in the main branch. It should support any OS that supports version 1.1.0.0 of the IISAdministration module which I believe means Windows 8 or Server 2012 R2 or newer. The major benefit over the older function is that this one should work in PowerShell 7+ as well as legacy PowerShell 5.1.