Virtual-environments: Error installing Ruby to tools cache on Windows

[domyd]

Describe the bug
I'm repeatedly getting an error in the Download-ToolCache.ps1 script, specifically when it gets to installing Ruby:

2020/02/06 18:34:03 ui error: ==> hyperv-iso: MSYS2 seems to be properly installed
2020/02/06 18:34:03 ui error: ==> hyperv-iso: Install MSYS2 and MINGW development toolchain ...
2020/02/06 18:34:03 ui error: ==> hyperv-iso: > pacman -S --needed --noconfirm autoconf autoconf2.13 autogen automake-wrapper automake1.10 automake1.11 automake1.12 automake1.13 automake1.14 automake1.15 automake1.6 automake1.7 automake1.8 automake1.9 diffutils file gawk grep libtool m4 make patch pkg-config sed texinfo texinfo-tex wget mingw-w64-x86_64-binutils mingw-w64-x86_64-crt-git mingw-w64-x86_64-gcc mingw-w64-x86_64-gcc-libs mingw-w64-x86_64-headers-git mingw-w64-x86_64-libmangle-git mingw-w64-x86_64-libwinpthread-git mingw-w64-x86_64-make mingw-w64-x86_64-pkg-config mingw-w64-x86_64-tools-git mingw-w64-x86_64-winpthreads-git
2020/02/06 18:34:04 ui error: ==> hyperv-iso: warning: file-5.37-1 is up to date -- skipping
2020/02/06 18:34:04 ui error: ==> hyperv-iso: warning: gawk-5.0.0-1 is up to date -- skipping
2020/02/06 18:34:04 ui error: ==> hyperv-iso: warning: grep-3.0-2 is up to date -- skipping
2020/02/06 18:34:04 ui:     hyperv-iso: resolving dependencies...
2020/02/06 18:34:04 ui:     hyperv-iso: looking for conflicting packages...
2020/02/06 18:34:04 ui error: ==> hyperv-iso: warning: m4-1.4.18-2 is up to date -- skipping
2020/02/06 18:34:04 ui:     hyperv-iso:
2020/02/06 18:34:04 ui:     hyperv-iso: Packages (51) automake1.16-1.16.1-1  db-5.3.28-2  gdbm-1.18.1-2  libatomic_ops-7.6.10-1  libgc-7.6.8-1  libgdbm-1.18.1-2  libguile-2.2.4-3  libltdl-2.4.6-6  mingw-w64-x86_64-expat-2.2.6-1  mingw-w64-x86_64-gettext-0.19.8.1-8  mingw-w64-x86_64-gmp-6.1.2-1  mingw-w64-x86_64-isl-0.21-1  mingw-w64-x86_64-libiconv-1.16-1  mingw-w64-x86_64-mpc-1.1.0-1  mingw-w64-x86_64-mpfr-4.0.2-2  mingw-w64-x86_64-windows-default-manifest-6.4-3  mingw-w64-x86_64-zlib-1.2.11-7  perl-5.28.2-1  tar-1.32-1  autoconf-2.69-5  autoconf2.13-2.13-2  autogen-5.18.16-1  automake-wrapper-11-1  automake1.10-1.10.3-3  automake1.11-1.11.6-3  automake1.12-1.12.6-3  automake1.13-1.13.4-4  automake1.14-1.14.1-3  automake1.15-1.15.1-1  automake1.6-1.6.3-2  automake1.7-1.7.9-2  automake1.8-1.8.5-3  automake1.9-1.9.6-2  diffutils-3.7-1  libtool-2.4.6-6  make-4.2.1-1  mingw-w64-x86_64-binutils-2.30-5  mingw-w64-x86_64-crt-git-7.0.0.5449.a0647123-1  mingw-w64-x86_64-gcc-8.3.0-2  mingw-w64-x86_64-gcc-libs-8.3.0-2  mingw-w64-x86_64-headers-git-7.0.0.5449.a0647123-1  mingw-w64-x86_64-libmangle-git-7.0.0.5230.69c8fad6-1  mingw-w64-x86_64-libwinpthread-git-7.0.0.5447.a2d94c81-1  mingw-w64-x86_64-make-4.2.1-2  mingw-w64-x86_64-pkg-config-0.29.2-1  mingw-w64-x86_64-tools-git-7.0.0.5394.0dfb3d3f-1  mingw-w64-x86_64-winpthreads-git-7.0.0.5447.a2d94c81-1  patch-2.7.6-1  pkg-config-0.29.2-1  texinfo-6.6-1  texinfo-tex-6.6-1
2020/02/06 18:34:04 ui error: ==> hyperv-iso: warning: sed-4.7-1 is up to date -- skipping
2020/02/06 18:34:04 ui error: ==> hyperv-iso: warning: wget-1.20.3-1 is up to date -- skipping
2020/02/06 18:34:04 ui:     hyperv-iso:
2020/02/06 18:34:04 ui:     hyperv-iso: Total Download Size:    86.15 MiB
2020/02/06 18:34:04 ui:     hyperv-iso: Total Installed Size:  524.71 MiB
2020/02/06 18:34:04 ui:     hyperv-iso:
2020/02/06 18:34:04 ui:     hyperv-iso: :: Proceed with installation? [Y/n]
2020/02/06 18:34:04 ui:     hyperv-iso: :: Retrieving packages...
2020/02/06 18:34:05 ui:     hyperv-iso: downloading mingw-w64-x86_64-libiconv-1.16-1-any.pkg.tar.xz...
2020/02/06 18:34:06 ui:     hyperv-iso: downloading mingw-w64-x86_64-zlib-1.2.11-7-any.pkg.tar.xz...
2020/02/06 18:34:06 ui:     hyperv-iso: downloading mingw-w64-x86_64-binutils-2.30-5-any.pkg.tar.xz...
2020/02/06 18:34:16 ui error: ==> hyperv-iso: error: failed retrieving file 'mingw-w64-x86_64-binutils-2.30-5-any.pkg.tar.xz' from repo.msys2.org : Operation too slow. Less than 1 bytes/sec transferred the last 10 seconds
2020/02/06 18:34:18 ui:     hyperv-iso: downloading mingw-w64-x86_64-binutils-2.30-5-any.pkg.tar.xz...
2020/02/06 18:34:29 ui:     hyperv-iso: downloading mingw-w64-x86_64-binutils-2.30-5-any.pkg.tar.xz...
2020/02/06 18:34:29 ui error: ==> hyperv-iso: error: failed retrieving file 'mingw-w64-x86_64-binutils-2.30-5-any.pkg.tar.xz' from sourceforge.net : Operation too slow. Less than 1 bytes/sec transferred the last 10 seconds
2020/02/06 18:34:30 ui:     hyperv-iso: downloading mingw-w64-x86_64-headers-git-7.0.0.5449.a0647123-1-any.pkg.tar.xz...
2020/02/06 18:34:34 ui:     hyperv-iso: downloading mingw-w64-x86_64-crt-git-7.0.0.5449.a0647123-1-any.pkg.tar.xz...
2020/02/06 18:34:37 ui:     hyperv-iso: downloading mingw-w64-x86_64-isl-0.21-1-any.pkg.tar.xz...

The actual file varies (as far as I can tell) and it happens more than once on various files. Those errors occur consistently and I haven't been able to produce an image since the change to the GitHub package tool cache.

I have not yet tried this outside of our corporate firewall, but I'd think those are http(s) requests so it shouldn't matter?

This issue seems related: https://github.com/msys2/MSYS2-packages/issues/1658

Full log of the Download-ToolCache.ps1 script: packer-mingw-error-log.txt (Yes, this was a week ago; I tried it again today with the latest master and it still fails)

Area for Triage:
Ruby

Question, Bug, or Feature?:
Bug

Virtual environments affected

• [ ] macOS 10.15
• [ ] Ubuntu 16.04 LTS
• [ ] Ubuntu 18.04 LTS
• [X] Windows Server 2016 R2
• [X] Windows Server 2019

Expected behavior
I expect it to finish the Download-ToolCache.ps1 script successfully.

Actual behavior
Download-ToolCache.ps1 fails when installing Ruby.

There's nothing all that special that I'm doing; I'm running the exact same set of provisioning steps, except on Hyper-V and not on Azure.

[al-cheb]

Hello, @domyd

I can't reproduce this issue from my side. Looks like transient network issue when downloading packages.

[jmos5156]

I seem to hit a similar issue with the ToolCache when building an agent in azure. The hash value is not the same

    vhd: Check if current Python version is installed...
    vhd: Check for installed Python3.8 32-bit WMI...
    vhd: Create Python 3.8.1 folder in C:\hostedtoolcache\windows\Python
    vhd: Copy Python binaries to C:\hostedtoolcache\windows\Python\3.8.1\x86
    vhd: Install Python 3.8.1 in C:\hostedtoolcache\windows\Python...
    vhd: Looking in links: c:\Users\packer\AppData\Local\Temp\tmpx77ch97e
    vhd: Requirement already satisfied: setuptools in c:\hostedtoolcache\windows\python\3.8.1\x86\lib\site-packages (41.2.0)
    vhd: Requirement already satisfied: pip in c:\hostedtoolcache\windows\python\3.8.1\x86\lib\site-packages (19.2.3)
    vhd: Collecting pip
    vhd:   Using cached https://files.pythonhosted.org/packages/54/0c/d01aa759fdc501a58f431eb594a17495f15b88da142ce14b5845662c13f3/pip-20.0.2-py2.py3-none-any.whl
    vhd: Installing collected packages: pip
    vhd:   Found existing installation: pip 19.2.3
    vhd:     Uninstalling pip-19.2.3:
    vhd:       Successfully uninstalled pip-19.2.3
    vhd: Successfully installed pip-20.0.2
    vhd: Create complete file
==> vhd: npm WARN saveError ENOENT: no such file or directory, open 'C:\Users\packer\AppData\Local\Temp\package.json'
    vhd: + @actions/[email protected]
==> vhd: npm WARN enoent ENOENT: no such file or directory, open 'C:\Users\packer\AppData\Local\Temp\package.json'
    vhd: updated 1 package in 52.781s
==> vhd: npm WARN Temp No description
==> vhd: npm WARN Temp No repository field.
    vhd: Installing npm @actions/[email protected] from https://npm.pkg.github.com/
==> vhd: npm WARN Temp No README data
==> vhd: npm WARN Temp No license field.
==> vhd:
    vhd: @actions/[email protected] installation failure;  Error: 1
==> vhd: npm ERR! code EINTEGRITY
==> vhd: npm ERR! sha512-DYFv0v90dmvZSdqq1f7Tbce14UffcgxarelaQiG9CUhr7gW4x94ldWSkKZA/DrlF6IwOcrchAc2yxJAqzPWS2Q== integrity checksum failed when using sha512: wanted sha512-DYFv0v90dmvZSdqq1f7Tbce14UffcgxarelaQiG9CUhr7gW4x94
ldWSkKZA/DrlF6IwOcrchAc2yxJAqzPWS2Q== but got sha512-m2iVptm4wUv3XZ4bfpeXOPNET44hLKyXamHLPYT5KVqBQrmgKUmoynBEPMRojuTlAPdejJmv2+npA2UcdLcO9w==. (64174877 bytes)
==> vhd:
==> vhd: npm ERR! A complete log of this run can be found in:
==> vhd: npm ERR!     C:\npm\cache\_logs\2020-02-21T11_29_38_314Z-debug.log
==> vhd: Provisioning step had errors: Running the cleanup provisioner, if present...
==> vhd: Removing the created Deployment object: 'pkrdpc3gn2wuc1e'
==> vhd: Azure token expired. Saving the refreshed token...
==> vhd: Removing the created Deployment object: 'kvpkrdpc3gn2wuc1e'
==> vhd: 
==> vhd: Cleanup requested, deleting resource group ...
==> vhd: Resource group has been deleted.
Build 'vhd' errored: Script exited with non-zero exit status: 1.Allowed exit codes are: [0]

[al-cheb]

Hello, @domyd and @jmos5156
Any updates?

[domyd]

Now that I'm doing home office, I'll try and run it outside of our corp firewall within the next few days. I'm guessing that it'll work, given that nobody else has this issue.

[jmos5156]

Sorry not been able to test this, I keep getting errors when installing Python which is a separate issue to this one.

[domyd]

It appears that this was just a transient issue or a problem with our firewall. I haven't gotten any such errors when testing today. This issue is closed from my side.