Windows 10 -- Performance issues when uploading VMWare tools due to Windows Defender's Realtime Protection

[GeoffWilliams]

Using VMWare Workstation 15, packer 1.3.1, host ubuntu 18.04 I get Error uploading VMware Tools. The VM can be seen grinding away at 100% CPU and the upload eventually times out:

2018/10/27 12:10:15 packer: 2018/10/27 12:10:15 [INFO] starting remote command: powershell.exe -EncodedCommand aQBmACAAKABUAGUAcwB0AC0AUABhAHQAaAAgAHYAYQByAGkAYQBiAGwAZQA6AGcAbABvAGIAYQBsADoAUAByAG8AZwByAGUAcwBzAFAAcgBlAGYAZQByAGUAbgBjAGUAKQB7ACQAUAByAG8AZwByAGUAcwBzAFAAcgBlAGYAZQByAGUAbgBjAGUAPQAnAFMAaQBsAGUAbgB0AGwAeQBDAG8AbgB0AGkAbgB1AGUAJwB9ADsAIABlAGMAaABvACAAIgBXAGkAbgBSAE0AIABjAG8AbgBuAGUAYwB0AGUAZAAuACIA
2018/10/27 12:10:15 packer: 2018/10/27 12:10:15 [INFO] command 'powershell.exe -EncodedCommand aQBmACAAKABUAGUAcwB0AC0AUABhAHQAaAAgAHYAYQByAGkAYQBiAGwAZQA6AGcAbABvAGIAYQBsADoAUAByAG8AZwByAGUAcwBzAFAAcgBlAGYAZQByAGUAbgBjAGUAKQB7ACQAUAByAG8AZwByAGUAcwBzAFAAcgBlAGYAZQByAGUAbgBjAGUAPQAnAFMAaQBsAGUAbgB0AGwAeQBDAG8AbgB0AGkAbgB1AGUAJwB9ADsAIABlAGMAaABvACAAIgBXAGkAbgBSAE0AIABjAG8AbgBuAGUAYwB0AGUAZAAuACIA' exited with code: 0
    vmware-iso: WinRM connected.
    vmware-iso: #< CLIXML
2018/10/27 12:10:15 packer: 2018/10/27 12:10:15 Connected to machine
    vmware-iso: <Objs Version="1.1.0.1" xmlns="http://schemas.microsoft.com/powershell/2004/04"><Obj S="progress" RefId="0"><TN RefId="0"><T>System.Management.Automation.PSCustomObject</T><T>System.Object</T></TN><MS><I64 N="SourceId">1</I64><PR N="Record"><AV>Preparing modules for first use.</AV><AI>0</AI><Nil /><PI>-1</PI><PC>-1</PC><T>Completed</T><SR>-1</SR><SD> </SD></PR></MS></Obj><Obj S="progress" RefId="1"><TNRef RefId="0" /><MS><I64 N="SourceId">1</I64><PR N="Record"><AV>Preparing modules for first use.</AV><AI>0</AI><Nil /><PI>-1</PI><PC>-1</PC><T>Completed</T><SR>-1</SR><SD> </SD></PR></MS></Obj></Objs>
==> vmware-iso: Connected to WinRM!
2018/10/27 12:10:15 packer: 2018/10/27 12:10:15 Uploading file to 'windows.iso'
==> vmware-iso: Uploading the 'windows' VMware Tools
==> vmware-iso: Error uploading VMware Tools: Error uploading file to $env:TEMP\winrmcp-b5741928-c52e-4768-6fc2-031307baab9a.tmp: upload operation returned code=3221225794
2018/10/27 12:20:01 ui error: ==> vmware-iso: Error uploading VMware Tools: Error uploading file to $env:TEMP\winrmcp-b5741928-c52e-4768-6fc2-031307baab9a.tmp: upload operation returned code=3221225794
2018/10/27 12:20:01 packer: 2018/10/27 12:20:01 Executing: /usr/bin/vmrun -T ws list
2018/10/27 12:20:01 packer: 2018/10/27 12:20:01 stdout: Total running VMs: 1
2018/10/27 12:20:01 packer: /home/geoff/github/boxcutter_windows/output-vmware-iso/eval-win10x64-enterprise.vmx
2018/10/27 12:20:01 packer: 2018/10/27 12:20:01 stderr:
==> vmware-iso: Stopping virtual machine...
2018/10/27 12:20:01 packer: 2018/10/27 12:20:01 Executing: /usr/bin/vmrun -T ws stop output-vmware-iso/eval-win10x64-enterprise.vmx hard
2018/10/27 12:20:03 packer: 2018/10/27 12:20:03 stdout:
2018/10/27 12:20:03 packer: 2018/10/27 12:20:03 stderr:
2018/10/27 12:20:03 packer: 2018/10/27 12:20:03 Deleting floppy disk: /tmp/packer987397621
==> vmware-iso: Deleting output directory...
2018/10/27 12:20:04 [INFO] (telemetry) ending vmware-iso
2018/10/27 12:20:04 ui error: Build 'vmware-iso' errored: Error uploading VMware Tools: Error uploading file to $env:TEMP\winrmcp-b5741928-c52e-4768-6fc2-031307baab9a.tmp: upload operation returned code=3221225794
2018/10/27 12:20:04 Builds completed. Waiting on interrupt barrier...
2018/10/27 12:20:04 machine readable: error-count []string{"1"}
2018/10/27 12:20:04 ui error: 
==> Some builds didn't complete successfully and had errors:
2018/10/27 12:20:04 machine readable: vmware-iso,error []string{"Error uploading VMware Tools: Error uploading file to $env:TEMP\\winrmcp-b5741928-c52e-4768-6fc2-031307baab9a.tmp: upload operation returned code=3221225794"}
2018/10/27 12:20:04 ui error: --> vmware-iso: Error uploading VMware Tools: Error uploading file to $env:TEMP\winrmcp-b5741928-c52e-4768-6fc2-031307baab9a.tmp: upload operation returned code=3221225794
==> Builds finished but no artifacts were created.
2018/10/27 12:20:04 [INFO] (telemetry) Finalizing.
Build 'vmware-iso' errored: Error uploading VMware Tools: Error uploading file to $env:TEMP\winrmcp-b5741928-c52e-4768-6fc2-031307baab9a.tmp: upload operation returned code=3221225794

==> Some builds didn't complete successfully and had errors:
--> vmware-iso: Error uploading VMware Tools: Error uploading file to $env:TEMP\winrmcp-b5741928-c52e-4768-6fc2-031307baab9a.tmp: upload operation returned code=3221225794

==> Builds finished but no artifacts were created.
2018/10/27 12:20:06 waiting for all plugin processes to complete...
2018/10/27 12:20:06 /usr/local/bin/packer: plugin process exited
2018/10/27 12:20:06 /usr/local/bin/packer: plugin process exited
2018/10/27 12:20:06 /usr/local/bin/packer: plugin process exited
Makefile:492: recipe for target 'box/vmware/eval-win10x64-enterprise-nocm-1.0.4.box' failed
make: *** [box/vmware/eval-win10x64-enterprise-nocm-1.0.4.box] Error 1

The fix for this seems to be to just add more memory and CPU. I increased to 4 CPUs and 4096MB ram and the problem went away instantly.

[sjames-au]

I hit this problem with win2016 as well as w10x64-enterprise on MacOS (Catalina) and Fusion 11.5. With w2016 increasing the ram/cpu did not help. Inspecting during the ISO upload was happening showed Defender consuming a large amount of memory and CPU.

I tried limiting defender by adding exclusion paths for the vagrant user and the entire C drive. This did not resolve the issue. I finally bit the bullet for my lab purposes and disabled the real time inspection early on, then re-enabled in the provisioning steps. Not my preferred approach as AV shouldn't cause this sort of headache.

This may be a packer issue rather than boxcutter but wanted to share my fix here:

`
diff --git a/eval-win10x64-enterprise.json b/eval-win10x64-enterprise.json
index 3d4e361..ef0163a 100644
--- a/eval-win10x64-enterprise.json
+++ b/eval-win10x64-enterprise.json
@@ -14,6 +14,7 @@
"{{template_dir}}/floppy/disablewinupdate.bat",
"{{template_dir}}/floppy/eval-win10x64-enterprise/Autounattend.xml",
"{{template_dir}}/floppy/fixnetwork.ps1",

•    "{{template_dir}}/floppy/limitAV.cmd",
     "{{template_dir}}/floppy/install-winrm.cmd",
     "{{template_dir}}/floppy/passwordchange.bat",
     "{{template_dir}}/floppy/powerconfig.bat",
  

@@ -32,6 +33,7 @@
"cpus": "{{ user cpus }}",
"memory": "{{ user memory }}",
"disk_adapter_type": "lsisas1068",

•  "version": "10",
   "vmx_data": {
     "cpuid.coresPerSocket": "1"
   },
  

@@ -172,6 +174,7 @@
],
"scripts": [
"{{template_dir}}/script/vagrant.bat",

•    "{{template_dir}}/script/unlimitAV.cmd",
     "{{template_dir}}/script/cmtool.bat",
     "{{template_dir}}/script/vmtool.bat",
     "{{template_dir}}/script/clean.bat",
  

diff --git a/eval-win2016-standard.json b/eval-win2016-standard.json
index 88c13bd..dbc620e 100644
--- a/eval-win2016-standard.json
+++ b/eval-win2016-standard.json
@@ -11,6 +11,7 @@
"{{template_dir}}/floppy/disablewinupdate.bat",
"{{template_dir}}/floppy/eval-win2016-standard/Autounattend.xml",
"{{template_dir}}/floppy/fixnetwork.ps1",

•    "{{template_dir}}/floppy/limitAV.cmd",
     "{{template_dir}}/floppy/install-winrm.cmd",
     "{{template_dir}}/floppy/passwordchange.bat",
     "{{template_dir}}/floppy/powerconfig.bat",
  

@@ -164,6 +165,7 @@
],
"scripts": [
"{{template_dir}}/script/vagrant.bat",

•    "{{template_dir}}/script/unlimitAV.cmd",
     "{{template_dir}}/script/cmtool.bat",
     "{{template_dir}}/script/vmtool.bat",
     "{{template_dir}}/script/clean.bat",
  

`

[arizvisa]

100% CPU definitely smells like AV. I'm from the infosec industry and I apologize that my peers have imposed this crap on you. Is this only happening whilst installing the VMware tools? Or does it happen during the whole provisioning process?

@stootles, that's very strange that adding it to the exclusion paths didn't result in this preventing windefend from hijacking the cpu. What're you doing to disable the AV? Are you explicitly stopping the service? Would you be interested in submitting a PR?

[arizvisa]

@GeoffWilliams, I'm going to re-title this issue so that it mentions the performance problem symptom and that its likely related to Windows Defender. If you're not cool with that, let me know and I'll simply revert it (or you can re-title it).

[sjames-au]

The file floppy/slim_win10.bat includes a capability to disable the AV. I did try a new things such as adding c:\ as an exclusion as well as disabled real time scanning. At the time I just added some powershell tasks to do so.

This really bothered me (I am in infosec as well) and did some digging on this as I wondered if the problem was not so much the AV but that winrm from python for file transfer appears to be an overall issue. I don't know the winrm subsystem as far as file transfers go but did hypothesize that perhaps the way the file transfers occur that each chunk is getting added to a logical file somewhere within the subsystem and the AV begins scanning the file from the start again, this could cause the AV to think it is dealing with thousands of files being uploaded. Its a theory and probably wrong.

I didnt keep my work as I started tinkering with the windows-ps stream and then bumping into the packer-windoze project that is using ansible, which just happens to align to wanting to spend more time with ansible myself (and isnt a terrible solution for solving the DRY challenges of various different windows versions).

[arizvisa]

Yeah, typically the way that people are doing file transfers are literally encoding it over the command-line, and not even keeping the file handle open.. So assuming that the AV is hooking these APIs, I'm pretty sure your theory is 100% correct. Both Python and Packer used to be doing something similar by appending to the file using '>>' or out-file iirc. I think only the ruby folk are actually doing this correctly and using the newer capabilities of the ws-man api. packer-community/winrmcp#6 (comment)

Still though, I believe during provisioning we should be properly excluding our installer directories. I think this might be happening because our provisioning scripts are using the %TEMP% directory to stage our installs. The hyperv-iso builder's branch for script/vmtool.bat is also not installing some required some KBs that'll need to be fixed too

Anyways, I just finished merging a number of older PRs that use up-to-date methodologies for provisioning the config management tools, so I'll look at optimizing/fixing the performance of these newer templates next because I think some of them are currently having problems w/ bitsadmin, forcing you to choose your wim at the beginning, or even downloading the wrong image entirely.

I'll update this issue with some more facts about reproducing this particular issue and how I plan to fix them when I get there. Thanks for your guys' insights!