Packer: Packer 1.2.2 and 1.2.3 : Error uploading ps script containing env vars: Couldn't determine whether destination was a folder or file: Command has already been closed

[vikasvijay]

2018/05/03 19:59:44 ui error: Build 'Win12R2' errored: Error processing command: Error uploading ps script containing env vars: Couldn't determine whether destination was a folder or file: Command has already been closed
2018/05/03 19:59:44 Builds completed. Waiting on interrupt barrier...
2018/05/03 19:59:44 machine readable: error-count []string{"1"}
2018/05/03 19:59:44 ui error:
==> Some builds didn't complete successfully and had errors:
2018/05/03 19:59:44 machine readable: Win12R2,error []string{"Error processing command: Error uploading ps script containing env vars: Couldn't determine whether destination was a folder or file: Command has already been closed"}
2018/05/03 19:59:44 ui error: --> Win12R2: Error processing command: Error uploading ps script containing env vars: Couldn't determine whether destination was a folder or file: Command has already been closed

[SwampDragons]

This doesn't happen to me -- What is the architecture of your host? Do you have a simple repro case for me? What builder are you using?

[vikasvijay]

Running the windows 2012r2 build on Jenkins server and instance is getting created on AWS. We do not see same issue everytime. For example, if we run build 10 times, 6-7 times their is a failure with same reason and 3-4 times it is successful.

[DanHam]

@vikasvijay We really need to see the full debug logs and build template in order to help further. Unfortunately it's impossible to try and diagnose the fault with the information provided so far.

Could you also please tell us if the builds are running directly on the Jenkins server? What OS is Packer being run on?

Have you tried running the build manually to see if you can reproduce the problem?

Could you also please include the script/userdata script that you use to set up WinRM.

[fearnosurf]

I see this exact error, it randomly happens after different scripts. Honestly it does not seem to be build script related, it seems to be packer losing connectivity with the instance or timing out. The question I have is how do we get better logging so we can pinpoint the issue? My PACKER_LOG is already at 1.

2018/05/07 23:12:56 packer: 2018/05/07 23:12:56 [INFO] 73 bytes written for 'uploadData'
2018/05/07 23:12:56 [INFO] 73 bytes written for 'uploadData'
2018/05/07 23:12:56 [INFO] (telemetry) ending powershell
2018/05/07 23:12:56 ui: ==> Win12R2: Terminating the source AWS instance...
2018/05/07 23:12:57 packer: 2018/05/07 23:12:57 Waiting for state to become: terminated
2018/05/07 23:12:57 packer: 2018/05/07 23:12:57 Using 2s as polling delay (change with AWS_POLL_DELAY_SECONDS)
2018/05/07 23:12:57 packer: 2018/05/07 23:12:57 Allowing 300s to complete (change with AWS_TIMEOUT_SECONDS)
2018/05/07 23:13:29 ui: ==> Win12R2: Cleaning up any extra volumes...
2018/05/07 23:13:30 ui: ==> Win12R2: No volumes to clean up, skipping
2018/05/07 23:13:30 [INFO] (telemetry) ending amazon-ebs
2018/05/07 23:13:30 ui error: Build 'Win12R2' errored: Error processing command: Error uploading ps script containing env vars: Couldn't determine whether destination was a folder or file: unknown error Post https://x.x.x.x:5986/wsman: dial tcp x.x.x.x:5986: connect: connection refused
2018/05/07 23:13:30 Builds completed. Waiting on interrupt barrier...
2018/05/07 23:13:30 machine readable: error-count []string{"1"}
2018/05/07 23:13:30 ui error:
==> Some builds didn't complete successfully and had errors:
2018/05/07 23:13:30 machine readable: Win12R2,error []string{"Error processing command: Error uploading ps script containing env vars: Couldn't determine whether destination was a folder or file: unknown error Post https://x.x.x.x:5986/wsman: dial tcp x.x.x.x:5986: connect: connection refused"}
2018/05/07 23:13:30 ui error: --> Win12R2: Error processing command: Error uploading ps script containing env vars: Couldn't determine whether destination was a folder or file: unknown error Post https://x.x.x.x:5986/wsman: dial tcp x.x.x.x:5986: connect: connection refused
2018/05/07 23:13:30 ui:
==> Builds finished but no artifacts were created.
2018/05/07 23:13:30 [INFO] (telemetry) Finalizing.
2018/05/07 23:13:30 [WARN] (telemetry) Error finalizing report. This is safe to ignore. Post https://checkpoint-api.hashicorp.com/v1/telemetry/packer: x509: certificate signed by unknown authority
2018/05/07 23:13:30 waiting for all plugin processes to complete...
2018/05/07 23:13:30 /home/ubuntu/packer: plugin process exited
2018/05/07 23:13:30 /home/ubuntu/packer: plugin process exited
2018/05/07 23:13:30 /home/ubuntu/packer: plugin process exited
2018/05/07 23:13:30 /home/ubuntu/packer: plugin process exited
2018/05/07 23:13:30 /home/ubuntu/packer: plugin process exited
2018/05/07 23:13:30 [ERR] Error decoding response stream 57: EOF
2018/05/07 23:13:30 [ERR] Error decoding response stream 60: EOF
2018/05/07 23:13:30 [ERR] Error decoding response stream 63: EOF
2018/05/07 23:13:30 /home/ubuntu/packer: plugin process exited

[DanHam]

@fearnosurf Thanks for reporting. Would you be able to post Gist's of:

• The build template and scripts you are using (or some representative version that will reproduce the issue).
• Any user_data_file's that you are using to configure WinRM/set up the instance.
• The full debug log for the failed build

I would really like to get to the bottom of this, and these would really help out. Many thanks.

[DanHam]

@SwampDragons

I've tried without success to replicate this using the Windows 2012R2 template HERE. I've run the builder about 5 times without error using Packer v1.2.3.

That said, it's apparent that the error messages reported are originating from the use of RunWithString in communicator/winrm/communicator.go HERE.

While looking into this I came across THIS PR in the upstream WinRM package that fixes a race condition in RunWithString (and incidentally RunWithInput). The intermittent nature of the reported issue and some of the error messages seen, tend to suggest that this race condition could be the culprit. The PR mentions that the race condition could lead to 'strange results'; Additionally, the race condition only manifests itself with Go >= 1.10 which would explain why we are seeing these problems with the latest versions of Packer.

With this in mind I figured upgrading to the latest version of the upstream package may fix the issue.
Of course, I could be wrong, and I'm certainly not 100% confident this is the cause of the issue as I have been unable to reproduce. That said, since there is an issue with the current version of the upstream package it may not hurt to upgrade regardless.

Please see #6261

@vikasvijay @fearnosurf Would you be able to test with the fix applied? If you need pre-built binaries to test with please let us know what OS you are using and (hopefully!) @SwampDragons will be kind enough to build them.

[SwampDragons]

Thanks for looking into this Dan; seems like a good place to start. Looking at logs and the Jenkins comment I'm going to guess @vikasvijay and @fearnosurf are both on Linux -- here's a build:
packer.zip

[jingyuan-au]

Hi @vikasvijay ,
I had a similar issue and navigated to here by google.
Not sure this is related or not, but I'd like to share the solution to my case:
In the template file (ami.json), extend the time inpause_before in provisioners which looks like this:

"provisioners": [
    {
      "type": "file",
      "pause_before":"120s"
    }
  ]

I changed this from "60s" to "120s" and problem solved. :)

[DanHam]

@jing-y-au This issue was hopefully fixed by #6261 and should not occur in the latest version of Packer. You should now be able to take out any workarounds you had in place.

Please let us know if you are still encountering issues and, if so, please provide full debug logs so that we can take a look at what is causing the problem.

Many thanks

[jingyuan-au]

@DanHam Will try. Thanks.

[Wenzel]

Hi,
I'm using Packer v1.2.4, and it this issue just appeared while i was provisioning a Windows VM.
So has it been fixed already, or scheduled for the next release ?
~
Build 'qemu' errored: Error processing command: Error uploading ps script containing env vars: Couldn't determine whether destination was a folder or file: Command has already been closed
~

[rickard-von-essen]

This is fixed in 1.2.4

[Wenzel]

@rickard-von-essen sorry, but i have been using v1.2.4, and I still have these issues from time to time.

I will run my builds with PACKER_LOG=1 and send you the output when the bug will be triggered again.

[rickard-von-essen]

Yes please do that on an new issue and reference this.

[DanHam]

This may be a separate issue from the one originally reported. #6481 may fix - this should make its way into 1.3.0

@SwampDragons may be able to produce a binary for you to test with...

[NamelessHH]

we're having the same issue on a packer build we're running on codebuild. It always happens after a powershell provider has run and its really sporadic.

Error processing command: Error uploading ps script containing env vars: Couldn't determine whether destination was a folder or file: Command has already been closed

Error processing command: Error uploading ps script containing env vars: Couldn't determine whether destination was a folder or file: Command has already been closed

[SwampDragons]

This fix will be out with the next release, which will go out early next week.

[hashibot[bot]]

I'm going to lock this issue because it has been closed for _30 days_ ⏳. This helps our maintainers find and focus on the active issues.

If you have found a problem that seems similar to this, please open a new issue and complete the issue template so we can capture all the details necessary to investigate further.