GCEMetadataScripts.exe crashes when trying to install pipx

[cfstras]

Reproduction

Create a Windows Server VM with a windows-startup-script-ps1 which contains the following:

Set-ExecutionPolicy Bypass -Scope Process -Force
[System.Net.ServicePointManager]::SecurityProtocol = [System.Net.ServicePointManager]::SecurityProtocol -bor 3072
iex ((New-Object System.Net.WebClient).DownloadString('https://community.chocolatey.org/install.ps1'))
Set-ExecutionPolicy Default -Scope Process

C:\ProgramData\chocolatey\bin\choco.exe install -y python312

Actual Output

# ... Installation of chocolatey removed from output


GCEMetadataScripts.exe:  Chocolatey v2.2.2
GCEMetadataScripts.exe:  Installing the following packages:
GCEMetadataScripts.exe:  python312
GCEMetadataScripts.exe:  By installing, you accept licenses for the packages.
Progress: Downloading KB2919355 1.0.20160915... 100%
GCEMetadataScripts.exe:
GCEMetadataScripts.exe:  KB2919355 v1.0.20160915 [Approved]
GCEMetadataScripts.exe:  KB2919355 package files install completed. Performing other installation steps.
GCEMetadataScripts.exe:  Skipping installation because this hotfix only applies to Windows 8.1 and Windows Server 2012 R2.
GCEMetadataScripts.exe:   The install of KB2919355 was successful.
GCEMetadataScripts.exe:    Software install location not explicitly set, it could be in package or
GCEMetadataScripts.exe:    default install location of installer.
Progress: Downloading KB2999226 1.0.20181019... 100%
GCEMetadataScripts.exe:
GCEMetadataScripts.exe:  KB2999226 v1.0.20181019 [Approved]
GCEMetadataScripts.exe:  KB2999226 package files install completed. Performing other installation steps.
GCEMetadataScripts.exe:  Skipping installation because update KB2999226 does not apply to this operating system (Microsoft Windows Server 2022 Datacenter).
GCEMetadataScripts.exe:   The install of KB2999226 was successful.
GCEMetadataScripts.exe:    Software install location not explicitly set, it could be in package or
GCEMetadataScripts.exe:    default install location of installer.
Progress: Downloading KB3035131 1.0.3... 100%
GCEMetadataScripts.exe:
GCEMetadataScripts.exe:  KB3035131 v1.0.3 [Approved]
GCEMetadataScripts.exe:  KB3035131 package files install completed. Performing other installation steps.
GCEMetadataScripts.exe:  Skipping installation because update KB3035131 does not apply to this operating system (Microsoft Windows Server 2022 Datacenter).
GCEMetadataScripts.exe:   The install of KB3035131 was successful.
GCEMetadataScripts.exe:    Software install location not explicitly set, it could be in package or
GCEMetadataScripts.exe:    default install location of installer.
Progress: Downloading KB3033929 1.0.5... 100%
GCEMetadataScripts.exe:
GCEMetadataScripts.exe:  KB3033929 v1.0.5 [Approved]
GCEMetadataScripts.exe:  KB3033929 package files install completed. Performing other installation steps.
GCEMetadataScripts.exe:  Skipping installation because update KB3033929 does not apply to this operating system (Microsoft Windows Server 2022 Datacenter).
GCEMetadataScripts.exe:   The install of KB3033929 was successful.
GCEMetadataScripts.exe:    Software install location not explicitly set, it could be in package or
GCEMetadataScripts.exe:    default install location of installer.
Progress: Downloading vcredist140 14.40.33810... 100%
GCEMetadataScripts.exe:
GCEMetadataScripts.exe:  vcredist140 v14.40.33810 [Approved]
GCEMetadataScripts.exe:  vcredist140 package files install completed. Performing other installation steps.
GCEMetadataScripts.exe:  Downloading vcredist140-x86
GCEMetadataScripts.exe:    from 'https://download.visualstudio.microsoft.com/download/pr/9c69db26-cda4-472d-bdae-f2b87f4a0177/A32DD41EAAB0C5E1EAA78BE3C0BB73B48593DE8D97A7510B97DE3FD993538600/VC_redist.x86.exe'
Progress: 100% - Completed download of C:\Windows\TEMP\chocolatey\vcredist140\14.40.33810\VC_redist.x86.exe (13.22 MB).
GCEMetadataScripts.exe:  Download of VC_redist.x86.exe (13.22 MB) completed.
GCEMetadataScripts.exe:  Hashes match.
GCEMetadataScripts.exe:  Installing vcredist140-x86...
GCEMetadataScripts.exe:  vcredist140-x86 has been installed.
GCEMetadataScripts.exe:  Downloading vcredist140-x64 64 bit
GCEMetadataScripts.exe:    from 'https://download.visualstudio.microsoft.com/download/pr/1754ea58-11a6-44ab-a262-696e194ce543/3642E3F95D50CC193E4B5A0B0FFBF7FE2C08801517758B4C8AEB7105A091208A/VC_redist.x64.exe'
Progress: 100% - Completed download of C:\Windows\TEMP\chocolatey\vcredist140\14.40.33810\VC_redist.x64.exe (24.22 MB).
GCEMetadataScripts.exe:  Download of VC_redist.x64.exe (24.22 MB) completed.
GCEMetadataScripts.exe:  Hashes match.
GCEMetadataScripts.exe:  Installing vcredist140-x64...
GCEMetadataScripts.exe:  vcredist140-x64 has been installed.
GCEMetadataScripts.exe:    vcredist140 may be able to be automatically uninstalled.
GCEMetadataScripts.exe:   The install of vcredist140 was successful.
GCEMetadataScripts.exe:    Software installed as 'exe', install location is likely default.
Progress: Downloading vcredist2015 14.0.24215.20170201... 100%
GCEMetadataScripts.exe:
GCEMetadataScripts.exe:  vcredist2015 v14.0.24215.20170201 [Approved]
GCEMetadataScripts.exe:  vcredist2015 package files install completed. Performing other installation steps.
GCEMetadataScripts.exe:   The install of vcredist2015 was successful.
GCEMetadataScripts.exe:    Software installed to 'C:\ProgramData\chocolatey\lib\vcredist2015'
GCEMetadataScripts.exe: error while communicating with "windows-startup-script-ps1" script: bufio.Scanner: token too long

Result

• Metadata Script logs error GCEMetadataScripts.exe: error while communicating with "windows-startup-script-ps1" script: bufio.Scanner: token too long
• Ends prematurely
• Not running any lines after the choco install.

Expected result

• No error
• Continue running

The reason for this is probably because choco will try to overwrite the previous line (CR instead of CRLF) while printing progress lines.

Detail

Here's an excerpt of what choco's output looks like when piped through xxd:

00003ce0: 5d0d 0a76 6372 6564 6973 7432 3031 3520  ]..vcredist2015
00003cf0: 7061 636b 6167 6520 6669 6c65 7320 696e  package files in
00003d00: 7374 616c 6c20 636f 6d70 6c65 7465 642e  stall completed.
00003d10: 2050 6572 666f 726d 696e 6720 6f74 6865   Performing othe
00003d20: 7220 696e 7374 616c 6c61 7469 6f6e 2073  r installation s
00003d30: 7465 7073 2e0d 0a20 5468 6520 696e 7374  teps... The inst
00003d40: 616c 6c20 6f66 2076 6372 6564 6973 7432  all of vcredist2
00003d50: 3031 3520 7761 7320 7375 6363 6573 7366  015 was successf
00003d60: 756c 2e0d 0a20 2053 6f66 7477 6172 6520  ul...  Software
00003d70: 696e 7374 616c 6c65 6420 746f 2027 433a  installed to 'C:
00003d80: 5c50 726f 6772 616d 4461 7461 5c63 686f  \ProgramData\cho
00003d90: 636f 6c61 7465 795c 6c69 625c 7663 7265  colatey\lib\vcre
00003da0: 6469 7374 3230 3135 270d 0a0d 5072 6f67  dist2015'...Prog
00003db0: 7265 7373 3a20 446f 776e 6c6f 6164 696e  ress: Downloadin
00003dc0: 6720 7079 7468 6f6e 3331 3220 332e 3132  g python312 3.12
00003dd0: 2e35 2e2e 2e20 250d 5072 6f67 7265 7373  .5... %.Progress
00003de0: 3a20 446f 776e 6c6f 6164 696e 6720 7079  : Downloading py
00003df0: 7468 6f6e 3331 3220 332e 3132 2e35 2e2e  thon312 3.12.5..
00003e00: 2e20 250d 5072 6f67 7265 7373 3a20 446f  . %.Progress: Do
00003e10: 776e 6c6f 6164 696e 6720 7079 7468 6f6e  wnloading python
00003e20: 3331 3220 332e 3132 2e35 2e2e 2e20 250d  312 3.12.5... %.
00003e30: 5072 6f67 7265 7373 3a20 446f 776e 6c6f  Progress: Downlo
00003e40: 6164 696e 6720 7079 7468 6f6e 3331 3220  ading python312
00003e50: 332e 3132 2e35 2e2e 2e20 250d 5072 6f67  3.12.5... %.Prog
00003e60: 7265 7373 3a20 446f 776e 6c6f 6164 696e  ress: Downloadin
00003e70: 6720 7079 7468 6f6e 3331 3220 332e 3132  g python312 3.12
00003e80: 2e35 2e2e 2e20 250d 5072 6f67 7265 7373  .5... %.Progress
00003e90: 3a20 446f 776e 6c6f 6164 696e 6720 7079  : Downloading py
00003ea0: 7468 6f6e 3331 3220 332e 3132 2e35 2e2e  thon312 3.12.5..
00003eb0: 2e20 250d 5072 6f67 7265 7373 3a20 446f  . %.Progress: Do
00003ec0: 776e 6c6f 6164 696e 6720 7079 7468 6f6e  wnloading python
00003ed0: 3331 3220 332e 3132 2e35 2e2e 2e20 250d  312 3.12.5... %.
00003ee0: 5072 6f67 7265 7373 3a20 446f 776e 6c6f  Progress: Downlo
00003ef0: 6164 696e 6720 7079 7468 6f6e 3331 3220  ading python312
00003f00: 332e 3132 2e35 2e2e 2e20 250d 5072 6f67  3.12.5... %.Prog
00003f10: 7265 7373 3a20 446f 776e 6c6f 6164 696e  ress: Downloadin
00003f20: 6720 7079 7468 6f6e 3331 3220 332e 3132  g python312 3.12
00003f30: 2e35 2e2e 2e20 250d 5072 6f67 7265 7373  .5... %.Progress
00003f40: 3a20 446f 776e 6c6f 6164 696e 6720 7079  : Downloading py
00003f50: 7468 6f6e 3331 3220 332e 3132 2e35 2e2e  thon312 3.12.5..
00003f60: 2e20 250d 5072 6f67 7265 7373 3a20 446f  . %.Progress: Do
00003f70: 776e 6c6f 6164 696e 6720 7079 7468 6f6e  wnloading python
00003f80: 3331 3220 332e 3132 2e35 2e2e 2e20 250d  312 3.12.5... %.
00003f90: 5072 6f67 7265 7373 3a20 446f 776e 6c6f  Progress: Downlo
00003fa0: 6164 696e 6720 7079 7468 6f6e 3331 3220  ading python312
00003fb0: 332e 3132 2e35 2e2e 2e20 250d 5072 6f67  3.12.5... %.Prog

You can see it uses 0d (CR) to move the cursor back to the start of the line, not detecting that this is not an interactive terminal.
Still, this shouldn't break startup scripts.

A workaround is to just pipe the output to NUL.

[a-crate]

@dorileo I see you assigned #215 to yourself, this is essentially the same.

[cfstras]

Please note that what wasn't reported in #215; this problem will actually cause GCEMetadaScripts to crash, which terminates any processes that have been started by the startup scripts - which is the main workload of the machine in our case.