Closed dwierima-aspentech closed 5 months ago
The problem here doesn't look like anything to do with win_template
but rather trying to start PowerShell. You can see the decoded CLIXML message is:
Program 'powershell.exe' failed to run: Win32 internal error "Access is denied" 0x5 occurred while reading the console output buffer. Contact Microsoft Customer Support Services.At line:1 char:1
+ PowerShell -NoProfile -NonInteractive -ExecutionPolicy Unrestricted - ...
+ ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~.
At line:1 char:1
+ PowerShell -NoProfile -NonInteractive -ExecutionPolicy Unrestricted - ...
+ ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
+ CategoryInfo : ResourceUnavailable: (:) [], ApplicationFailedException
+ FullyQualifiedErrorId : NativeCommandFailed
Something is breaking internally in the ssh daemon that is causing an access denied failure. Unfortunately for an error such as this it's going to be something environment specific as it's a fundamental issue with trying to start powershell.exe to run our code.
I thought that initially as well, however, in the Set Path Variable
play I see the same access denied error, which leads me to believe it's a non-fatal error.
It's a separate issue, but when researching that error message I found multiple threads reporting that that access denied error occurs when running powershell commands from a non-interactive ssh session. This thread explains that it's an issue with specific versions of OpenSSH, where powershell doesn't handle data sent to stdout in a non-interactive ssh session. And when decoding the encoded powershell command, there is a write-output
command, and it would make sense to me if that triggered the same issue.
But again, that error shows up multiple times in my logs on plays that succeeded, so I don't believe it's causing the 'Unable to create Temporary Directory' error.
Ah I see, the temp directory is created and outputted as expected but as the return value of the process to create the temporary directory is not 0 the connection plugin sees the command as a failure.
Unfortunately at the point in time the rc is being checked is not something this collection can control, it's part of shared code inside Ansible which validates whether the return code was 0 or not. This would need to fixed on the transport layer to ensure that a non-zero rc is not returned for scenarios like this unfortunately.
From what I can tell the error is being caused by attempting to create a temp directory that already exists. Decoding the temp directory path, it seems that a timestamp is included in the temp directory name, most likely to avoid the issue of creating duplicate directory names. However, because the same directory gets created twice, it seems that it's not generating a new directory name for the win_template
play.
Is it possible to either re-generate the temp directory name, or skip creating a directory at all? When I decode the command that gets run on Windows 2022, it seems that a temp directory isn't created at all.
From what I can tell the error is being caused by attempting to create a temp directory that already exists
That can't happen as the temporary directory has enough randomness in it to avoid conflicts. The shell plugin uses _generate_temp_dir_name to create the directory name which uses both time, the pid, and a random integer between 0 and 2^48. The temporary directory is also scoped to each task so doing subsequent win_template
tasks will use their own temp path. The only exception to this is using multiple tasks in a loop but Ansible is smart enough to only create the temp path once. When you decode the -EncodedCommand
being run you can see that the PowerShell script being run by the connection plugin is
Set-StrictMode -Version Latest
$tmp_path = [System.Environment]::ExpandEnvironmentVariables('%TEMP%')
$tmp = New-Item -Type Directory -Path $tmp_path -Name 'ansible-tmp-1714509461.069503-301-253568139436398'
Write-Output -InputObject $tmp.FullName
If (-not $?) { If (Get-Variable LASTEXITCODE -ErrorAction SilentlyContinue) { exit $LASTEXITCODE } Else { exit 1 } }
One of the last step is to output the temporary directory which if we look at the stdout we can see that is the case:
exited with result 1, stdout output: C:\Users\<username>\AppData\Local\Temp\ansible-tmp-1714509461.069503-301-253568139436398
If it was an issue where the same directory is created twice stderr would contain the error
New-Item: An item with the specified name ... already exists
There's nothing about the output that would indicate it's being created twice, it seems like it's being created but because of the internal error in PowerShell about the output stream it is exiting with 1 causing the subsequent failures. You need to solve the problem with ssh here to ensure it doesn't return the rc of 1.
The reason I say that the same temp directory is getting created twice is because if I decode the command for the Set Path Variable
it results in:
Set-StrictMode -Version Latest
$tmp_path = [System.Environment]::ExpandEnvironmentVariables('%TEMP%')
$tmp = New-Item -Type Directory -Path $tmp_path -Name 'ansible-tmp-1714509461.069503-301-253568139436398'
Write-Output -InputObject $tmp.FullName
If (-not $?) { If (Get-Variable LASTEXITCODE -ErrorAction SilentlyContinue) { exit $LASTEXITCODE } Else { exit 1 } }
Which is the exact same command down to the temp path that gets sent during the Setup ntp.conf
play.
I think your output might be mixed and the messages you see is actually for the template task and not the win_path
one. I say that because the output comes back after the win_path
result is shown so that module has already run and Ansible has processed the result. Also unless you've opted into preserving the temp files Ansible won't create a temp directory for normal module invocations as it pipelines the data, win_template
is only doing it because it needs to create the temp directory to store the file that is being copied.
Ahh, that makes a lot of sense. The log output format is a bit weird, and that definetly explains why it looks like it's creating the same folder twice. Looks like this issue isn't what I thought it was, so I'm going to close this ticket.
Thanks for all your help.
For anyone else that runs into this issue, I solved it. It's specifically caused by PowerShell transcription getting turned on (HKLM:\SoftwarePolicies\Microsoft\Windows\PowerShell\Transcription EnableTranscripting). This setting seems to interact weirdly with the version of OpenSSH 7.7p1, which was causing the Access is Denied
error that I was seeing above.
This same bug does not appear to be occurring on Windows 2022 which has is running OpenSSH 8.1p1 with PowerShell transcription enabled.
Awesome glad you figured what the underlying cause was. A pity the OpenSSH server is causing issue with it though.
SUMMARY
Running win_template module against a Windows 2019 Server results in a 'Failed to create temporary directory' error. This same behavior is not exhibited by Windows Server 2022, Windows desktop 10 or 11, when running the exact same play. I believe this is due to win_template attempting to create a temporary directory that was already created in a previous play. For instance in my most recent testing I see the following path in stdout of the win_template play, and the previous win_path play: "C:\Users\username\AppData\Local\Temp\ansible-tmp-1714509461.069503-301-253568139436398" However, when I decode the same play when run against Windows server 2022, ansible doesn't even appear to be creating a temporary directory.
I have a lot of plays in this playbook, and I have attempted shuffling around the order that the plays in the playbook get called, and adding a 5 second pause prior to running the win_template play, however the win_template play always throws the error. Which is why I believe that this error is caused by win_template.
ISSUE TYPE
COMPONENT NAME
win_template
ANSIBLE VERSION
COLLECTION VERSION
CONFIGURATION
OS / ENVIRONMENT
STEPS TO REPRODUCE
EXPECTED RESULTS
Running the above play produces the following output on Windows Server 2022, where the file is templeted out correctly.
ACTUAL RESULTS
Running the same play as above produces the following output on Windows Server 2019, where an unreachable error occurs. I included both the play which produces an error and the previous play to show that they both create the same temp directory.