From 8c21282024ad085b0bd84ba363c2c23d47ff76a6 Mon Sep 17 00:00:00 2001 From: cproudlock Date: Thu, 6 Aug 2026 14:18:25 -0400 Subject: [PATCH] Verify staging in WinPE, harvest imaging logs, make enrollment run once Three changes aimed at the same failure mode: a bay that images green and is silently unusable, diagnosed only by walking over and copying files off by hand. VERIFY STAGING (startnet, at :pctype_done) Checks pc-type.txt, Run-ShopfloorSetup.ps1, shopfloor-setup/common and shopfloor-setup/ exist on the applied volume before anything depends on them, retries the small trees once, and prints a loud banner if the retry does not fix it. The enrollment package is checked but never blindly re-pulled - it is 8 GB, so a miss is reported instead. Done here because a tech is still at the machine: a short copy found in WinPE costs 30 seconds, the same copy found at first logon costs 20 minutes, and found never costs a rebuild. Four Display bays sat green at stage 2 for weeks. HARVEST LOGS (startnet, after PESetup exits) Collects X:\*.log, the generated X:\Unattend.xml, PESetup's own log from the target's Panther directory and winpe-staging.log into \\enrollment\imaging-logs\\, plus a build-context.txt naming PCTYPE, PPKG, machine number and media. All of it was being discarded at reboot. Runs after PESetup exits so the logs are final, which means re-mapping Y: since cleanup already dropped it. Best-effort throughout - a bay must never fail to reboot because a log copy failed. W: WAIT CAP 20 -> 45 MINUTES 270 polls instead of 120. Fine on NVMe either way, but a WIM apply can exceed 20 minutes on slow media, and the failure mode is the os_not_found banner plus nothing staged. The loop still exits the moment the SYSTEM hive appears. RUN-ENROLLMENT RUNS ONCE Marker at C:\Enrollment\.ppkg-applied, written on exit 0 and also on 0x800700B7 ERROR_ALREADY_EXISTS. Observed running twice on 579C144; the second pass re-applied a pending rename over the package's own and otherwise did nothing. Verified: startnet parens balance, every goto resolves, 899 CRLF lines with no bare LF; run-enrollment parses clean under the PowerShell parser. Deployed - boot.wim md5 159c2a4d, live run-enrollment dce9d50a. --- playbook/shopfloor-setup/run-enrollment.ps1 | 25 ++++- playbook/startnet.cmd | 110 +++++++++++++++++++- 2 files changed, 133 insertions(+), 2 deletions(-) diff --git a/playbook/shopfloor-setup/run-enrollment.ps1 b/playbook/shopfloor-setup/run-enrollment.ps1 index de4c1d8..35cb00f 100755 --- a/playbook/shopfloor-setup/run-enrollment.ps1 +++ b/playbook/shopfloor-setup/run-enrollment.ps1 @@ -19,6 +19,18 @@ function Log { Log "=== GE Aerospace GCCH Enrollment ===" +# --- Run once ------------------------------------------------------------ +# This script has been observed running twice on one build (579C144, +# 2026-08-06: 13:31:55 and 13:36:45). The second provtool call returned +# 0x800700B7 ERROR_ALREADY_EXISTS and achieved nothing except re-applying a +# pending computer rename over the one the package had just set. The rename is +# gone now, but a second full pass is still pointless work on an 8 GB package. +$appliedMarker = 'C:\Enrollment\.ppkg-applied' +if (Test-Path $appliedMarker) { + Log "Provisioning package already applied on $(Get-Content $appliedMarker -First 1) - skipping." + return +} + # --- Find the .ppkg --- $ppkgFile = Get-ChildItem "C:\Enrollment\*.ppkg" -ErrorAction SilentlyContinue | Select-Object -First 1 if (-not $ppkgFile) { @@ -94,9 +106,20 @@ Log "PPKG diagnostic logs -> $ppkgLogDir (provtool writes them automatically)" try { $p = Start-Process -FilePath $provtool -ArgumentList $provArgs -Wait -PassThru -NoNewWindow -ErrorAction Stop Log "provtool.exe exit code: $($p.ExitCode)" - if ($p.ExitCode -ne 0) { + if ($p.ExitCode -eq 0) { + Set-Content -Path $appliedMarker -Value (Get-Date -Format 'yyyy-MM-dd HH:mm:ss') -ErrorAction SilentlyContinue + Log "Wrote applied-marker $appliedMarker" + } else { $hex = '0x{0:X8}' -f $p.ExitCode Log "WARNING: provtool.exe returned non-zero exit code ($hex). Check $ppkgLogDir for diagnostic bundle." + # 0x800700B7 ERROR_ALREADY_EXISTS means the package is already applied. + # That is a success for our purposes, and it is what a second run of + # this script produced on 579C144 (2026-08-06) - so mark it applied and + # let the next run skip instead of repeating the work. + if ($p.ExitCode -eq -2147024713) { + Set-Content -Path $appliedMarker -Value (Get-Date -Format 'yyyy-MM-dd HH:mm:ss') -ErrorAction SilentlyContinue + Log "Package was already applied (ERROR_ALREADY_EXISTS) - marker written." + } } } catch { Log "ERROR: Failed to launch provtool.exe: $_" diff --git a/playbook/startnet.cmd b/playbook/startnet.cmd index 5be5e20..a66b07b 100644 --- a/playbook/startnet.cmd +++ b/playbook/startnet.cmd @@ -422,7 +422,11 @@ if exist W:\Windows\System32\config\system ( goto found_os ) set /a OSWAIT+=1 -if %OSWAIT% GEQ 120 goto os_not_found +REM 270 polls at ~10s = 45 minutes. Was 120 (20 min), which is fine on NVMe but +REM tight on slow media - a WIM apply can run 25+ minutes there, and the failure +REM mode is the scary os_not_found banner plus nothing staged. Waiting longer +REM costs nothing: the loop exits the moment the SYSTEM hive appears. +if %OSWAIT% GEQ 270 goto os_not_found ping -n 11 127.0.0.1 >NUL goto wait_enroll @@ -765,6 +769,63 @@ echo WARNING: Y:\installers-post\waxtrace not found - WaxTrace PC cannot install :pctype_done if defined STAGELOG echo [%TIME%] WinPE staging complete >> "%STAGELOG%" +REM --- Verify what we just staged ------------------------------------------ +REM Check the payload BEFORE anything depends on it, while a tech is still +REM standing at the machine. A short copy found here costs 30 seconds; the same +REM copy found at first logon costs 20 minutes, and found never costs a rebuild. +REM Four Display bays sat at "imaging stage 2, green" for weeks because nothing +REM checked. Retry once for the small trees; the ppkg is 8 GB so report it +REM rather than blindly re-pulling it. +if "%PCTYPE%"=="" goto verify_done +set STAGEBAD= +if not exist "%OSDRIVE%\Enrollment\pc-type.txt" set STAGEBAD=%STAGEBAD% pc-type.txt +if not exist "%OSDRIVE%\Enrollment\Run-ShopfloorSetup.ps1" set STAGEBAD=%STAGEBAD% Run-ShopfloorSetup.ps1 +if not exist "%OSDRIVE%\Enrollment\shopfloor-setup\common" set STAGEBAD=%STAGEBAD% shopfloor-setup\common +if not exist "%OSDRIVE%\Enrollment\shopfloor-setup\%PCTYPE%" set STAGEBAD=%STAGEBAD% shopfloor-setup\%PCTYPE% +if "%STAGEBAD%"=="" goto verify_ppkg + +echo. +echo Staging verify: missing%STAGEBAD% - retrying once... +echo [%TIME%] VERIFY: missing%STAGEBAD% - retry >> "%STAGELOG%" +robocopy "Y:\shopfloor-setup" "%OSDRIVE%\Enrollment" "Run-ShopfloorSetup.ps1" /R:2 /W:2 /NFL /NDL /NJH /NJS +robocopy "Y:\shopfloor-setup\common" "%OSDRIVE%\Enrollment\shopfloor-setup\common" /E /MT:16 /R:2 /W:2 /NFL /NDL /NJH /NJS +robocopy "Y:\shopfloor-setup\%PCTYPE%" "%OSDRIVE%\Enrollment\shopfloor-setup\%PCTYPE%" /E /MT:16 /R:2 /W:2 /NFL /NDL /NJH /NJS +if not exist "%OSDRIVE%\Enrollment\pc-type.txt" echo %PCTYPE%> %OSDRIVE%\Enrollment\pc-type.txt + +set STAGEBAD= +if not exist "%OSDRIVE%\Enrollment\pc-type.txt" set STAGEBAD=%STAGEBAD% pc-type.txt +if not exist "%OSDRIVE%\Enrollment\Run-ShopfloorSetup.ps1" set STAGEBAD=%STAGEBAD% Run-ShopfloorSetup.ps1 +if not exist "%OSDRIVE%\Enrollment\shopfloor-setup\common" set STAGEBAD=%STAGEBAD% shopfloor-setup\common +if not exist "%OSDRIVE%\Enrollment\shopfloor-setup\%PCTYPE%" set STAGEBAD=%STAGEBAD% shopfloor-setup\%PCTYPE% +if "%STAGEBAD%"=="" ( + echo Staging verify: retry fixed it. + echo [%TIME%] VERIFY: retry succeeded >> "%STAGELOG%" + goto verify_ppkg +) +echo. +echo ****************************************************************** +echo STAGING INCOMPLETE after retry:%STAGEBAD% +echo This bay will image but the post-install setup will NOT run +echo properly. Fix the share and re-image. Tell the PXE admin. +echo ****************************************************************** +echo. +echo [%TIME%] VERIFY FAILED after retry:%STAGEBAD% >> "%STAGELOG%" + +:verify_ppkg +REM The enrollment package is the expensive one - 8 GB. Report, do not re-pull. +if "%PPKG%"=="" goto verify_done +if exist "%OSDRIVE%\Enrollment\%PPKG%" ( + echo Staging verify: enrollment package present. + echo [%TIME%] VERIFY: %PPKG% present >> "%STAGELOG%" +) else ( + echo. + echo WARNING: enrollment package %PPKG% is MISSING from %OSDRIVE%\Enrollment. + echo Enrollment will not run. Re-image this bay. + echo. + echo [%TIME%] VERIFY FAILED: %PPKG% missing >> "%STAGELOG%" +) +:verify_done + REM --- BIOS update sub-stage push (fires AFTER %OSDRIVE% copies complete) --- REM check-bios.cmd drops X:\bios-fired.flag iff it actually flashed or REM staged a firmware update. Reading the flag file is more reliable than @@ -784,6 +845,53 @@ net use Y: /delete 2>NUL ping -n 11 127.0.0.1 >NUL wmic process where "name='PESetup.exe'" get name 2>NUL | find /I "PESetup" >NUL if not errorlevel 1 goto wait_finish + +REM --- Harvest the imaging logs to the share -------------------------------- +REM Every diagnosis of a failed build so far has meant walking to the bay and +REM copying files off by hand. PESetup preserves its log and the generated +REM unattend, DISM writes its apply logs, and our staging log sits on the target +REM - all of it is thrown away at reboot unless collected now. Runs after +REM PESetup exits so the logs are final, which means re-mapping Y: (cleanup +REM already dropped it). +REM Best-effort throughout: a bay must never fail to reboot because a log copy +REM did not work. +set SERIAL= +for /f "skip=1 tokens=*" %%S in ('wmic bios get serialnumber 2^>NUL') do if not defined SERIAL set SERIAL=%%S +for /f "tokens=*" %%a in ("%SERIAL%") do set SERIAL=%%a +if "%SERIAL%"=="" set SERIAL=unknown-serial + +net use Y: \\172.16.9.1\enrollment /user:pxe-upload pxe /persistent:no >NUL 2>&1 +if not exist "Y:\" goto harvest_done +set LOGDEST=Y:\imaging-logs\%SERIAL% +mkdir "Y:\imaging-logs" 2>NUL +mkdir "%LOGDEST%" 2>NUL +echo Collecting imaging logs to %LOGDEST% ... + +REM WinPE side: DISM apply logs, the unattend PESetup generated, BIOS flash log. +robocopy X:\ "%LOGDEST%" "*.log" "Unattend.xml" /R:1 /W:1 /NFL /NDL /NJH /NJS >NUL 2>&1 +REM Target side: PESetup's own log lands in Panther, and our staging log. +if defined OSDRIVE ( + robocopy "%OSDRIVE%\Windows\Panther" "%LOGDEST%" "PESetup*.log" /R:1 /W:1 /NFL /NDL /NJH /NJS >NUL 2>&1 + robocopy "%OSDRIVE%\Enrollment" "%LOGDEST%" "winpe-staging.log" /R:1 /W:1 /NFL /NDL /NJH /NJS >NUL 2>&1 +) +REM A breadcrumb of what this build actually was, so the logs are readable +REM without cross-referencing the webapp. +> "%LOGDEST%\build-context.txt" ( +echo Serial=%SERIAL% +echo PCTYPE=%PCTYPE% +echo PPKG=%PPKG% +echo MACHINENUM=%MACHINENUM% +echo CMMID=%CMMID% +echo KEYENCEMODEL=%KEYENCEMODEL% +echo DISPLAYTYPE=%DISPLAYTYPE% +echo OSDRIVE=%OSDRIVE% +echo Media=%MEDIAPATH% +echo Date=%DATE% %TIME% +) +echo Imaging logs collected. +net use Y: /delete /y >NUL 2>&1 +:harvest_done + echo. echo Imaging complete. Rebooting in 15 seconds... echo Press Ctrl+C to cancel.