Validate-Msys2.ps1 fails on missing tar

[AtOMiCNebula]

Describe the bug
We're unable to build images using the win19/20200517.1 tag, and are failing a few hours into the process during running the newly-added Validate-Msys2.ps1 (#632). Log output below reports managedimage instead of vhd, since a pipeline I set up patches Windows2019-Azure.json to generate a managed image instead of a VHD, but otherwise doesn't change the file. We were able to use the win19/20200511.1 tag successfully (the previous tag).

2020-05-18T21:47:46.0174123Z ==> managedimage: Provisioning with powershell script: d:\a\1\s\virtual-environments\images\win/scripts/Installers/Validate-Msys2.ps1
2020-05-18T21:47:48.1377266Z     managedimage: Check installed tools in msys2/usr/bin directory
2020-05-18T21:47:48.1384664Z ==> managedimage: C:\Windows\Temp\script-5ec2c8a9-681b-7430-91e8-a477188b79a9.ps1 : The term 'C:\msys64\usr\bin\tar' is not recognized
2020-05-18T21:47:48.1393373Z ==> managedimage: as the name of a cmdlet, function, script file, or operable program. Check the spelling of the name, or if a path was
2020-05-18T21:47:48.1405350Z     managedimage: GNU bash, version 4.4.23(1)-release (x86_64-pc-msys)
2020-05-18T21:47:48.1411989Z     managedimage: Copyright (C) 2016 Free Software Foundation, Inc.
2020-05-18T21:47:48.1418422Z     managedimage: License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
2020-05-18T21:47:48.1426619Z     managedimage:
2020-05-18T21:47:48.1433984Z     managedimage: This is free software; you are free to change and redistribute it.
2020-05-18T21:47:48.1441809Z     managedimage: There is NO WARRANTY, to the extent permitted by law.
2020-05-18T21:47:48.1447744Z     managedimage: tar was not installed in MSYS2 bin directory
2020-05-18T21:47:48.1453342Z ==> managedimage: included, verify that the path is correct and try again.
2020-05-18T21:47:48.1455621Z ==> managedimage: At line:1 char:215
2020-05-18T21:47:48.1459994Z ==> managedimage: + ... 097926.ps1; &'c:/Windows/Temp/script-5ec2c8a9-681b-7430-91e8-a477188b ...
2020-05-18T21:47:48.1465475Z ==> managedimage: +                 ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
2020-05-18T21:47:48.1472344Z ==> managedimage:     + CategoryInfo          : NotSpecified: (:) [Write-Error], WriteErrorException
2020-05-18T21:47:48.1479506Z ==> managedimage:     + FullyQualifiedErrorId : Microsoft.PowerShell.Commands.WriteErrorException,script-5ec2c8a9-681b-7430-91e8-a477188
2020-05-18T21:47:48.1485879Z ==> managedimage:    b79a9.ps1
2020-05-18T21:47:48.1495081Z ==> managedimage:
2020-05-18T21:47:48.1500929Z ==> managedimage: Provisioning step had errors: Running the cleanup provisioner, if present...

Area for Triage:
Scripting and command line (maybe?)

Question, Bug, or Feature?:
Bug

Virtual environments affected

• macOS 10.15
• Ubuntu 16.04 LTS
• Ubuntu 18.04 LTS
• Windows Server 2016 R2
  • (possibly affected, we don't build this image variant so I can't confirm one way or another)
• Windows Server 2019

Expected behavior
Packer successfully builds the Windows2019-Azure.json image.

Actual behavior
Packer fails while building the Windows2019-Azure.json image. Not doing anything special with running Packer beyond patching the .json to output a managed image (instead of a VHD in a storage account).

[AtOMiCNebula]

Dug a little deeper on this one, and it looks like actual failures are happening inside Install-Msys2.ps1 but the script isn't bubbling them out, and Packer continues onward blissfully until the Validate script detects the fault. I guess it's good the validation script is there at least. 😄

First mention of errors in the Install-Msys2.ps1 output:

2020-05-18T21:31:39.2073455Z     managedimage: :: Retrieving packages...
2020-05-18T21:31:39.2080548Z     managedimage: downloading msys2-runtime-3.1.4-1-x86_64.pkg.tar.zst...
2020-05-18T21:31:39.2085519Z     managedimage: downloading bash-4.4.023-2-x86_64.pkg.tar.xz...
2020-05-18T21:31:39.2091521Z     managedimage: downloading filesystem-2020.02-2-x86_64.pkg.tar.xz...
2020-05-18T21:31:39.2097756Z     managedimage: downloading mintty-1~3.1.4-1-x86_64.pkg.tar.xz...
2020-05-18T21:31:39.2102940Z     managedimage: downloading pacman-mirrors-20200329-1-any.pkg.tar.xz...
2020-05-18T21:31:39.2104812Z     managedimage: downloading libzstd-1.4.4-2-x86_64.pkg.tar.xz...
2020-05-18T21:31:39.2106723Z     managedimage: downloading zstd-1.4.4-2-x86_64.pkg.tar.xz...
2020-05-18T21:31:39.2108374Z     managedimage: downloading pacman-5.2.1-6-x86_64.pkg.tar.xz...
2020-05-18T21:31:39.2111279Z     managedimage: checking keyring...
2020-05-18T21:31:39.2113974Z     managedimage: checking package integrity...
2020-05-18T21:31:40.7442614Z     managedimage: loading package files...
2020-05-18T21:31:40.7450567Z     managedimage: error: could not open file /var/cache/pacman/pkg/msys2-runtime-3.1.4-1-x86_64.pkg.tar.zst: Child process exited with status 127
2020-05-18T21:31:40.7469224Z     managedimage: error: failed to commit transaction (cannot open package file)
2020-05-18T21:31:40.7472462Z     managedimage: Errors occurred, no packages were upgraded.
2020-05-18T21:31:41.7150694Z     managedimage: :: Synchronizing package databases...

Full log for Install-Msys2.ps1 from my latest failed run (we've had two failures in a row):
InstallMsys2.log.txt

[vsafonkin]

@AtOMiCNebula , thank you for your help, this error is related to the last msys2 update:
msys2/MSYS2-packages#1962
msys2/MSYS2-packages#1960

We are trying to fix it at the moment.

[eine]

Ref msys2/MSYS2-packages#1962 (comment)

[al-cheb]

Hello, @AtOMiCNebula
We have merged PR with the fix - #899. Could you please rerun your build?

[AtOMiCNebula]

I will give it a shot and let you know. Thanks for the fast turnaround!

[AtOMiCNebula]

@al-cheb, the fix worked! Thanks. 😄