GoogleCloudPlatform / compute-image-windows

Windows agents and scripts for Google Compute Engine images.
Apache License 2.0
105 stars 65 forks source link

GCESysprep apparently hung for 3 hours and counting #156

Closed petemounce closed 5 years ago

petemounce commented 6 years ago

I'm not sure if this is the same issue as #154, but I have GCESysprep on Windows 2016 (image windows-server-2016-dc-v20180814) hung, apparently, while running sysprep.exe. I'm wondering whether I should continue waiting (~3 hours and counting), or write it off.

Edit: I elected to hit Stop in the cloud console; packer has treated that as a success and captured the image, but when I remote into an instance from it I'm presented with the "shutdown event tracker" helpfully asking me whether that was unplanned or not, and windeploy was not run, so I think this is not a clean end result.

Packer-side Logs (also visible via serial port):

....
2018/09/11 11:29:27 GCESysprep: Beginning GCESysprep.
2018/09/11 11:29:27 GCESysprep: No answer file was specified. Using default file.
2018/09/11 11:29:27 GCESysprep: Running 'schtasks' with arguments '/delete /tn GCEStartup /f'
2018/09/11 11:29:27 GCESysprep: --> SUCCESS: The scheduled task "GCEStartup" was successfully deleted.
2018/09/11 11:29:29 GCESysprep: Clearing events in EventViewer.
2018/09/11 11:29:31 GCESysprep: Running 'C:\Windows\System32\Sysprep\sysprep.exe' with arguments '/generalize /oobe /quit /unattend:C:\Program Files\Google\Compute Engine\sysprep\unattended.xml'

Triggered via packer provisioner (using -noshutdown because I need packer to manage the lifetime of the instance, otherwise it will treat the shutdown as an instance-death and fail the build):

{
  "type": "powershell",
  "inline": [
    "GCESysprep -NoShutdown"
  ]
}

Using sysinternals process explorer I can see that the process is alive; it's "C:\Windows\System32\Sysprep\sysprep.exe" /generalize /oobe /quit "/unattend:C:\Program Files\Google\Compute Engine\sysprep\unattended.xml". I have not customised the unattended.xml.

I can see that the image that I'm building (from the windows-2016 image family does not yet have @adjackura's change from 62223fe08b9fbb080b034aa09c4cfc138c8ba080 within it, yet - I took a look at the sysprep.ps1 and it lacks the /f flag - though the process itself has not executed to that point so far.

Inside C:\Windows\Panther\setupact.log (80KB, no longer growing) the last few lines are as follows. There are no Error level log lines. There are a few warnings, 2nd block. There's 0KB inside setuperr.log, but I don't know whether there are some lines pending being flushed by something.

Last few lines:

2018-09-11 10:12:38, Info                         [setup.exe] [Action Queue] : Identity 1: Microsoft-Windows-Deployment, Culture=neutral, Version=10.0.14393.2430, PublicKeyToken=31bf3856ad364e35, ProcessorArchitecture=amd64, versionScope=NonSxS
2018-09-11 10:12:38, Info                         [setup.exe] [Action Queue] : Using component order file C:\Windows\winsxs\amd64_microsoft-windows-servicingstack_31bf3856ad364e35_10.0.14393.2272_none_7f1843c421e0830a\GlobalInstallOrder.xml
2018-09-11 10:12:38, Info                  CSI    00000001@2018/9/11:10:12:38.995 WcpInitialize (wcp.dll version 0.0.0.6) called (stack @0x7fff06786ca9 @0x7fff070c7cb5 @0x7fff070c7baf @0x7fff070c69c3 @0x7fff070c7994 @0x7fff0e2d3467)
2018-09-11 10:12:39, Info                         [setup.exe] [Action Queue] : Found manifest file C:\Windows\Winsxs\Manifests\amd64_microsoft-windows-deployment_31bf3856ad364e35_10.0.14393.2430_none_718e65d647f7aa0d.manifest
2018-09-11 10:12:39, Info                         [setup.exe] [Action Queue] : Found manifest file C:\Windows\Winsxs\Manifests\amd64_microsoft-windows-shell-setup_31bf3856ad364e35_10.0.14393.0_none_ffcf3e270052d303.manifest
2018-09-11 10:12:39, Info                         [setup.exe] [Action Queue] : GenerateActionQueue finish (hr = 0x0)
2018-09-11 10:12:39, Info                         [setup.exe] [Action Queue] : ProcessActionQueue start
2018-09-11 10:12:39, Info                         [setup.exe] [Action Queue] : ProcessActionQueue using queue file C:\Windows\panther\actionqueue\specialize.uaq
2018-09-11 10:12:39, Info                         [setup.exe] [Action Queue] : Command Line = C:\WINDOWS\SYSTEM32\SETUPUGC.EXE / arguments =  / pass = specialize / manifest path = C:\Windows\Winsxs\Manifests\amd64_microsoft-windows-deployment_31bf3856ad364e35_10.0.14393.2430_none_718e65d647f7aa0d.manifest
2018-09-11 10:12:39, Info                         [setup.exe] [Action Queue] : Command Line = C:\WINDOWS\SYSTEM32\RUNDLL32.EXE / arguments = shsetup.dll,SHUnattendedSetup / pass = specialize / manifest path = C:\Windows\Winsxs\Manifests\amd64_microsoft-windows-shell-setup_31bf3856ad364e35_10.0.14393.0_none_ffcf3e270052d303.manifest
2018-09-11 10:12:39, Info                         [setup.exe] [Action Queue] : Executing command "C:\WINDOWS\SYSTEM32\SETUPUGC.EXE"  specialize
2018-09-11 10:12:41, Info                         [setup.exe] [Action Queue] : process exit code = 0
2018-09-11 10:12:41, Info                         [setup.exe] [Action Queue] : Unattend action returned operation complete.
2018-09-11 10:12:41, Info                         [setup.exe] [Action Queue] : Executing command "C:\WINDOWS\SYSTEM32\RUNDLL32.EXE" shsetup.dll,SHUnattendedSetup specialize
2018-09-11 10:12:41, Info                         [setup.exe] [Action Queue] : process exit code = 1
2018-09-11 10:12:41, Info                         [setup.exe] [Action Queue] : Unattend action requested delayed reboot.
2018-09-11 10:12:41, Info                         [setup.exe] [Action Queue] : ProcessActionQueue finish (hr = 0x2c1000)
2018-09-11 10:12:41, Info                         [setup.exe] One or more unattend GCs requested a delayed reboot; we will reboot the computer
2018-09-11 10:12:41, Info       [0x0606cc] IBS    Flushing registry to disk...
2018-09-11 10:12:41, Info       [0x0606cc] IBS    Flush took 16 ms.
2018-09-11 10:12:41, Info                  IBS    Callback_Unattend_InitiatePass: An unattend action requested a pending reboot; we'll restart the computer after Setup finishes...
2018-09-11 10:12:41, Warning    [0x06036c] IBS    Callback_SystemRestore: Failed to set System Restore state. GLE is [126]
2018-09-11 10:12:41, Info       [0x0606cc] IBS    GetSystemPartitionNTPath: Found system partition at [\Device\HarddiskVolume1].
2018-09-11 10:12:41, Info       [0x0606cc] IBS    GetSystemPartitionPath: Found non-NT drive path [C:\] for NT system partition path [\Device\HarddiskVolume1].
2018-09-11 10:12:41, Info       [0x0606cc] IBS    GetSystemPartitionNTPath: Found system partition at [\Device\HarddiskVolume1].
2018-09-11 10:12:41, Info       [0x0606cc] IBS    GetSystemPartitionPath: Found non-NT drive path [C:\] for NT system partition path [\Device\HarddiskVolume1].
2018-09-11 10:12:41, Info                  IBSLIB ModifyBootEntriesLegacy: Either boot.ini or ntldr was not found on the boot volume.  Assuming legacy booting was not being used.
2018-09-11 10:12:41, Info                  IBSLIB ModifyBootEntriesBCD:Setup phase is [4]
2018-09-11 10:12:41, Info       [0x060215] IBS    CallBack_MungeBootEntries:Successfully modified boot entries
2018-09-11 10:12:41, Info       [0x0605f6] IBS    Callback_Locale_InstallLayerDriver: The layer driver setting is missing or invalid: ignoring optional setting.
2018-09-11 10:12:41, Info       [0x060366] IBS    OnlineSetting_CreateBootstatDatFile: Found an existing bootstat.dat
2018-09-11 10:12:41, Info       [0x060367] IBS    OnlineSetting_CreateBootstatDatFile: Succeeded
2018-09-11 10:12:41, Info       [0x06035e] IBS    OnlineSetting_PatchPowerSettings: Successfully updated power settings.
2018-09-11 10:12:41, Info       [0x06035e] IBS    Callback_OnlineSettings: Successfully updated system legacy online settings
2018-09-11 10:12:41, Info       [0x0600b6] IBS    Callback_Unattend_Serialize:Unattend file path is C:\Windows\Panther\unattend.xml
2018-09-11 10:12:41, Info                  IBS    Callback_CleanupSensitiveBBData: Replacing entries under blackboard; entering new OS.
2018-09-11 10:12:41, Info                  IBS    Callback_CleanupSensitiveBBData: Finished clearing data; 0 items cleared.
2018-09-11 10:12:41, Info       [0x090093] PANTHR WdsEnableExit called!  When group #105 is empty, execution will stop, and the queue will be saved.
2018-09-11 10:12:41, Info       [0x070042] DIAG   CallBack_DiagnosticDataSend: Called with notification for SetupPhaseDone published by Engine
2018-09-11 10:12:41, Info                  DIAG   CallBack_DiagnosticDataSend: Setup was started from Phase 4. Disabling Diagnostics [DiagnosticDataSend] in this scenario
2018-09-11 10:12:41, Info       [0x090092] PANTHR WdsEnableExit already called
2018-09-11 10:12:41, Info                  UI     CallbackShowFinishOnline: Enter
2018-09-11 10:12:41, Info                  UI     CallbackShowFinishOnline: Exit
2018-09-11 10:12:41, Info       [0x09008e] PANTHR SeqExecute -- stopping, since termination group reached
2018-09-11 10:12:41, Info       [0x090086] PANTHR pWorkerThreadFunc -- Stopping
2018-09-11 10:12:41, Info       [0x090086] PANTHR pWorkerThreadFunc -- Stopping
2018-09-11 10:12:41, Info       [0x090086] PANTHR pWorkerThreadFunc -- Stopping
2018-09-11 10:12:41, Info       [0x0900c7] PANTHR SEQ EVENT_SERIALIZE_BEFORE_EXIT Received.  Will only save modules with persistent subscriptions!
2018-09-11 10:12:41, Info       [0x0900b7] PANTHR SerializeToFile: C:\Windows\Panther\MainQueueOnline0.que
2018-09-11 10:12:41, Info       [0x0900b8] PANTHR Saving Main Event Queue
2018-09-11 10:12:41, Info       [0x0900b9] PANTHR Saving Permanent Event Queue
2018-09-11 10:12:41, Info       [0x0900c5] PANTHR Queue Serialization Succeeded
2018-09-11 10:12:41, Info                  PANTHR DeleteCriticalSection for pExecQueue->csLock;
2018-09-11 10:12:41, Info       [0x0605a6] IBS    Requested UI to hide the language and locale selection pages.
2018-09-11 10:12:41, Info       [0x090081] PANTHR Destroying any unreferenced modules! (SEQ6)
2018-09-11 10:12:41, Info       [0x0601dc] IBS    Setup has completed phase 4 at 2018-09-11 10:12:41
2018-09-11 10:12:41, Info                  IBS    Successfully logged OS information onto event viewer system channel
2018-09-11 10:12:41, Info       [0x0601e1] IBS    InstallWindows:First boot phase of setup done!!!!
2018-09-11 10:12:41, Info       [0x090009] PANTHR CBlackboard::Close: c:\windows\panther\setupinfo.

Warning occurences:

2018-09-11 10:12:27, Warning               SYSPRP ActionPlatform::GetValue: Error from RegQueryValueEx on value SysprepMode under key HKEY_LOCAL_MACHINE\Software\Microsoft\Windows\CurrentVersion\Setup\Sysprep; dwRet = 0x2
...
2018-09-11 10:12:27, Warning               SYSPRP ActionPlatform::DeleteValue: Registry key HKEY_LOCAL_MACHINE\SOFTWARE\Microsoft\Windows NT\CurrentVersion\WOF, whose value is to be deleted, does not exist
2018-09-11 10:12:27, Warning               SYSPRP ActionPlatform::DeleteValue: Registry key HKEY_LOCAL_MACHINE\SOFTWARE\Microsoft\Windows NT\CurrentVersion\WOF, whose value is to be deleted, does not exist
...
2018-09-11 10:12:29, Warning               SYSPRP Ignoring folder Deleted because could not convert to family name
...
2018-09-11 10:12:32, Warning               TOOL   SpecializeBcdStore: The /detecthal switch could not be removed because it was not found.
...
2018-09-11 10:12:36, Warning                      [setup.exe] Recovery file not found at C:\Windows\system32\Recovery\ReCustomization.xml
2018-09-11 10:12:36, Warning                      [setup.exe] winreBackupRecoveryFile (C:\Windows\system32\Recovery\ReCustomization.xml, ReCustomization.xml) failed, Err: 2
...
2018-09-11 10:12:36, Warning               SYSPRP ActionPlatform::DeleteValue: Registry value DecompressOverride to be deleted does not exist under key HKEY_LOCAL_MACHINE\SOFTWARE\Microsoft\Windows\CurrentVersion\SideBySide
...
2018-09-11 10:12:36, Warning               SYSPRP ActionPlatform::DeleteValue: Registry value SysprepMode to be deleted does not exist under key HKEY_LOCAL_MACHINE\Software\Microsoft\Windows\CurrentVersion\Setup\Sysprep
...
2018-09-11 10:12:36, Warning    [0x0f008f] SYSPRP RunRegistryDlls:Registry key is either empty or malformed: SOFTWARE\Microsoft\Windows\CurrentVersion\Setup\SysPrepExternal\Specialize
...
2018-09-11 10:12:41, Warning    [0x06036c] IBS    Callback_SystemRestore: Failed to set System Restore state. GLE is [126]
...

I am naively suspicious of

in that while I'm definitely not very familiar with sysprep, those sound like oddities.

Finally, inside sysprep.ps1 I can see the snippet:

# Run sysprep.
Invoke-ExternalCommand C:\Windows\System32\Sysprep\sysprep.exe /generalize /oobe /quit /unattend:$ans_file

Write-Log 'Waiting for sysprep to complete.'

The log line suggests that it expects the Invoke-ExternalCommand cmdlet to be async, but by observation it is not. Is that an error in the intended behaviour, or the wording of the log message, or am I reading into it too much? When I have run non-powershell things from powershell, I think I've usually used Start-Process <path> <args> -wait -passthru - but I'm not a powershell expert, and I'm unfamiliar with the technique being used inside of https://github.com/GoogleCloudPlatform/compute-image-windows/blob/master/gce_base.psm1#L333 to know whether it will stream or wait until the command is done before giving any output.

Are there any other things I could provide to you, or try out, to see whether I can get a working sysprep?

adjackura commented 6 years ago

The change you mention wont impact you as you are running with the -noshutdown flag. It appears as though sysrep.exe is hanging for some reason, this is usually because of some issue with the OS like a previously failed sysprep run (this is all Windows sysprep and shouldn't have anything to do with the GCE specific wrapping code) C:\Windows\Panther\setupact.log wont tell you much as that is from the instance startup, for the list of logs see: https://docs.microsoft.com/en-us/windows-hardware/manufacture/desktop/windows-setup-log-files-and-event-logs You should take a look at c:\System32\Sysprep\Panther, that should show logs from the sysprep generalize run.

petemounce commented 6 years ago

Thanks for responding; I've retried (been working on something different). I'm now onto the 20180911 image. Now, gcesysprep ran but ended part way through. Output is below. I had a look inside c:\windows\system32\sysprep\panther\setuperr.log - that's pasted below too.

packer's output from the gcesysprep run:

    googlecompute: 2018/09/15 18:04:26 GCESysprep: Beginning GCESysprep.
    googlecompute: 2018/09/15 18:04:26 GCESysprep: No answer file was specified. Using default file.
    googlecompute: 2018/09/15 18:04:26 GCESysprep: Running 'schtasks' with arguments '/delete /tn GCEStartup /f'
    googlecompute: 2018/09/15 18:04:26 GCESysprep: --> SUCCESS: The scheduled task "GCEStartup" was successfully deleted.
    googlecompute: 2018/09/15 18:04:28 GCESysprep: Clearing events in EventViewer.
    googlecompute: 2018/09/15 18:04:30 GCESysprep: Running 'C:\Windows\System32\Sysprep\sysprep.exe' with arguments '/generalize /oobe /quit /unattend:C:\Program Files\Google\Compute Engine\sysprep\unattended.xml'

So - that's missing some output based on expectations reading the sysprep.ps1 wrapper, but it's also not returning an error, and I haven't figured out how that's possible so far.

c:\windows\system32\sysprep\panther\setuperr.log:

2018-09-11 19:59:53, Error                 SYSPRP setupdigetclassdevs failed with error 0
2018-09-11 19:59:53, Error                 SYSPRP MRTGeneralize:107 - ERROR: Failed DeleteInstance AntiSpywareProduct.instanceGuid="{D68DDC3A-831F-4FAE-9E44-DA132C1ACF46}" hr=2147749904
2018-09-11 19:59:53, Error                 SYSPRP MRTGeneralize:116 - ERROR: Failed DeleteInstance AntiVirusProduct.instanceGuid="{D68DDC3A-831F-4FAE-9E44-DA132C1ACF46}" hr=2147749904
2018-09-15 18:08:32, Error      [0x0f00b0] SYSPRP spopk.dll:: Failed to query pending CBS operations; hr = 0x80080005
2018-09-15 18:08:32, Error      [0x0f0082] SYSPRP ActionPlatform::LaunchModule: Failure occurred while executing 'Sysprep_Clean_Validate_Opk' from C:\Windows\System32\spopk.dll; dwRet = 0x5
2018-09-15 18:08:32, Error                 SYSPRP SysprepSession::Validate: Error in validating actions from C:\Windows\System32\Sysprep\ActionFiles\Cleanup.xml; dwRet = 0x5
2018-09-15 18:08:32, Error                 SYSPRP RunPlatformActions:Failed while validating SysprepSession actions; dwRet = 0x5
2018-09-15 18:08:32, Error      [0x0f0070] SYSPRP RunExternalDlls:An error occurred while running registry sysprep DLLs, halting sysprep execution. dwRet = 0x5
2018-09-15 18:08:32, Error      [0x0f00d8] SYSPRP WinMain:Hit failure while pre-validate sysprep cleanup internal providers; hr = 0x80070005

c:\windows\system32\sysprep\panther\setupact.log:

2018-09-15 18:04:30, Info                  SYSPRP ========================================================
2018-09-15 18:04:30, Info                  SYSPRP ===          Beginning of a new sysprep run          ===
2018-09-15 18:04:30, Info                  SYSPRP ========================================================
2018-09-15 18:04:30, Info       [0x0f004d] SYSPRP The time is now 2018-09-15 18:04:30
2018-09-15 18:04:30, Info       [0x0f004e] SYSPRP Initialized SysPrep log at C:\Windows\System32\Sysprep\Panther
2018-09-15 18:04:30, Info       [0x0f0054] SYSPRP ValidateUser:User has required privileges to sysprep machine
2018-09-15 18:04:30, Info       [0x0f007e] SYSPRP FCreateTagFile:Tag file C:\Windows\System32\Sysprep\Sysprep_succeeded.tag does not already exist, no need to delete anything
2018-09-15 18:04:30, Info       [0x0f005f] SYSPRP ParseCommands:Found supported command line option 'GENERALIZE'
2018-09-15 18:04:30, Info       [0x0f005f] SYSPRP ParseCommands:Found supported command line option 'OOBE'
2018-09-15 18:04:30, Info       [0x0f005f] SYSPRP ParseCommands:Found supported command line option 'QUIT'
2018-09-15 18:04:30, Info       [0x0f005f] SYSPRP ParseCommands:Found supported command line option 'UNATTEND'
2018-09-15 18:04:30, Info       [0x0f00d7] SYSPRP WinMain:Pre-validing 'cleanup' internal providers.
2018-09-15 18:04:30, Info                  SYSPRP RunExternalDlls:Running platform actions specified in action file for phase 3
2018-09-15 18:04:30, Info       [0x0f00ba] SYSPRP SysprepSession::CreateSession: Successfully created instance with mount path C:, action file C:\Windows\System32\Sysprep\ActionFiles\Cleanup.xml, and mode <null>
2018-09-15 18:04:30, Info                  SYSPRP SysprepSession::Validate: Beginning action execution from C:\Windows\System32\Sysprep\ActionFiles\Cleanup.xml
2018-09-15 18:04:30, Info                  SYSPRP ActionPlatform::GetStringValue: Getting REG_SZ value SysprepMode under key HKEY_LOCAL_MACHINE\Software\Microsoft\Windows\CurrentVersion\Setup\Sysprep
2018-09-15 18:04:30, Info                  SYSPRP ActionPlatform::GetValue: Getting value SysprepMode under key HKEY_LOCAL_MACHINE\Software\Microsoft\Windows\CurrentVersion\Setup\Sysprep
2018-09-15 18:04:30, Warning               SYSPRP ActionPlatform::GetValue: Error from RegQueryValueEx on value SysprepMode under key HKEY_LOCAL_MACHINE\Software\Microsoft\Windows\CurrentVersion\Setup\Sysprep; dwRet = 0x2
2018-09-15 18:04:30, Info                  SYSPRP SysprepSession::CreateXPathForSelection: Sysprep mode in registry is <null>
2018-09-15 18:04:30, Info                  SYSPRP ActionPlatform::GetStringValue: Getting REG_SZ value PROCESSOR_ARCHITECTURE under key HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Control\Session Manager\Environment
2018-09-15 18:04:30, Info                  SYSPRP ActionPlatform::GetValue: Getting value PROCESSOR_ARCHITECTURE under key HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Control\Session Manager\Environment
2018-09-15 18:04:30, Info                  SYSPRP SysprepSession::CreateXPathForSelection: Processor architecture in registry is AMD64
2018-09-15 18:04:30, Info       [0x0f0080] SYSPRP ActionPlatform::LaunchModule: Found 'Sysprep_Clean_Validate_Opk' in C:\Windows\System32\spopk.dll; executing it
2018-09-15 18:08:32, Error      [0x0f00b0] SYSPRP spopk.dll:: Failed to query pending CBS operations; hr = 0x80080005
2018-09-15 18:08:32, Error      [0x0f0082] SYSPRP ActionPlatform::LaunchModule: Failure occurred while executing 'Sysprep_Clean_Validate_Opk' from C:\Windows\System32\spopk.dll; dwRet = 0x5
2018-09-15 18:08:32, Error                 SYSPRP SysprepSession::Validate: Error in validating actions from C:\Windows\System32\Sysprep\ActionFiles\Cleanup.xml; dwRet = 0x5
2018-09-15 18:08:32, Error                 SYSPRP RunPlatformActions:Failed while validating SysprepSession actions; dwRet = 0x5
2018-09-15 18:08:32, Error      [0x0f0070] SYSPRP RunExternalDlls:An error occurred while running registry sysprep DLLs, halting sysprep execution. dwRet = 0x5
2018-09-15 18:08:32, Error      [0x0f00d8] SYSPRP WinMain:Hit failure while pre-validate sysprep cleanup internal providers; hr = 0x80070005
2018-09-15 18:25:29, Info                  SYSPRP ========================================================
2018-09-15 18:25:29, Info                  SYSPRP ===          Beginning of a new sysprep run          ===
2018-09-15 18:25:29, Info                  SYSPRP ========================================================
2018-09-15 18:25:29, Info       [0x0f004d] SYSPRP The time is now 2018-09-15 18:25:29
2018-09-15 18:25:29, Info       [0x0f004e] SYSPRP Initialized SysPrep log at C:\Windows\system32\Sysprep\Panther
2018-09-15 18:25:29, Info       [0x0f0054] SYSPRP ValidateUser:User has required privileges to sysprep machine
2018-09-15 18:25:29, Info       [0x0f007e] SYSPRP FCreateTagFile:Tag file C:\Windows\system32\Sysprep\Sysprep_succeeded.tag does not already exist, no need to delete anything
2018-09-15 18:25:29, Info       [0x0f005f] SYSPRP ParseCommands:Found supported command line option 'RESPECIALIZE'
2018-09-15 18:25:29, Info       [0x0f005f] SYSPRP ParseCommands:Found supported command line option 'QUIET'
2018-09-15 18:25:29, Info                  SYSPRP WinMain:Processing 're-specialize' internal provider request.
2018-09-15 18:25:29, Info                  SYSPRP RunExternalDlls:Running platform actions specified in action file for phase 6
2018-09-15 18:25:29, Info       [0x0f00ba] SYSPRP SysprepSession::CreateSession: Successfully created instance with mount path C:, action file C:\Windows\System32\Sysprep\ActionFiles\ReSpecialize.xml, and mode <null>
2018-09-15 18:25:29, Info                  SYSPRP SysprepSession::Execute: Beginning action execution from C:\Windows\System32\Sysprep\ActionFiles\ReSpecialize.xml
2018-09-15 18:25:29, Info                  SYSPRP ActionPlatform::GetStringValue: Getting REG_SZ value SysprepMode under key HKEY_LOCAL_MACHINE\Software\Microsoft\Windows\CurrentVersion\Setup\Sysprep
2018-09-15 18:25:29, Info                  SYSPRP ActionPlatform::GetValue: Getting value SysprepMode under key HKEY_LOCAL_MACHINE\Software\Microsoft\Windows\CurrentVersion\Setup\Sysprep
2018-09-15 18:25:29, Warning               SYSPRP ActionPlatform::GetValue: Error from RegQueryValueEx on value SysprepMode under key HKEY_LOCAL_MACHINE\Software\Microsoft\Windows\CurrentVersion\Setup\Sysprep; dwRet = 0x2
2018-09-15 18:25:29, Info                  SYSPRP SysprepSession::CreateXPathForSelection: Sysprep mode in registry is <null>
2018-09-15 18:25:29, Info                  SYSPRP ActionPlatform::GetStringValue: Getting REG_SZ value PROCESSOR_ARCHITECTURE under key HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Control\Session Manager\Environment
2018-09-15 18:25:29, Info                  SYSPRP ActionPlatform::GetValue: Getting value PROCESSOR_ARCHITECTURE under key HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Control\Session Manager\Environment
2018-09-15 18:25:29, Info                  SYSPRP SysprepSession::CreateXPathForSelection: Processor architecture in registry is AMD64
2018-09-15 18:25:29, Info                  SYSPRP SysprepSession::ExecuteInternal: After sorting, providers will be excuted in this order:
2018-09-15 18:25:29, Info                  SYSPRP SysprepSession::ExecuteInternal: name:Microsoft-Windows-PnpSysprep, order: 100d
2018-09-15 18:25:29, Info       [0x0f00bd] SYSPRP CreateSysprepActionList: Building action list for component Microsoft-Windows-PnpSysprep
2018-09-15 18:25:29, Info       [0x0f0080] SYSPRP ActionPlatform::LaunchModule: Found 'Sysprep_Respecialize_Pnp' in C:\Windows\System32\sppnp.dll; executing it
2018-09-15 18:25:29, Info                  SYSPRP SPPNP: Sysprep_Respecialize_Pnp: Enter
2018-09-15 18:25:29, Info                  SYSPRP SPPNP: Created progress thread.
2018-09-15 18:25:29, Info                  SYSPRP SPPNP: Creating device install status thread...
2018-09-15 18:25:29, Info                  SYSPRP SPPNP: Waiting for thread to exit...
2018-09-15 18:25:29, Info                  SYSPRP SPPNP: Waiting for service to start.
2018-09-15 18:25:29, Info                  SYSPRP SPPNP: Waiting for progress thread to exit.
2018-09-15 18:25:29, Info                  SYSPRP SPPNP: Status: Idle
2018-09-15 18:25:29, Info                  SYSPRP SPPNP: Finished waiting for device install status...
2018-09-15 18:25:29, Info                  SYSPRP SPPNP: Progress thread exited.
2018-09-15 18:25:29, Info                  SYSPRP SPPNP: Sysprep_Respecialize_Pnp: Exit
2018-09-15 18:25:29, Info       [0x0f0081] SYSPRP ActionPlatform::LaunchModule: Successfully executed 'Sysprep_Respecialize_Pnp' from C:\Windows\System32\sppnp.dll without error
2018-09-15 18:25:29, Info       [0x0f00b8] SYSPRP SysprepSession::Execute: Sysprep mode was not specified, deleting it from registry
2018-09-15 18:25:29, Info       [0x0f00c6] SYSPRP ActionPlatform::DeleteValue: Deleting registry value SysprepMode under key HKEY_LOCAL_MACHINE\Software\Microsoft\Windows\CurrentVersion\Setup\Sysprep
2018-09-15 18:25:29, Warning               SYSPRP ActionPlatform::DeleteValue: Registry value SysprepMode to be deleted does not exist under key HKEY_LOCAL_MACHINE\Software\Microsoft\Windows\CurrentVersion\Setup\Sysprep
2018-09-15 18:25:29, Info       [0x0f0052] SYSPRP Shutting down SysPrep log
2018-09-15 18:25:29, Info       [0x0f004d] SYSPRP The time is now 2018-09-15 18:25:29

One of the things I'm doing within my packer build is disable Windows Defender via Set-MpPreference -DisableBehaviorMonitoring $true -DisableIOAVProtection $true -DisableRealtimeMonitoring $true -DisableScanningNetworkFiles $true. That makes me think SYSPRP MRTGeneralize:107 - ERROR: Failed DeleteInstance AntiSpywareProduct.instanceGuid="{D68DDC3A-831F-4FAE-9E44-DA132C1ACF46}" hr=2147749904 is related, so I'll retry without doing that.

If it turns out it's related, I'll curse, then swap to disabling the thing via a startup script...

lmayorga1980 commented 6 years ago

I think I am having a related problem with SysPrep with Windows 2016 latest AMI(September 15th)

2018-09-16 20:44:02, Error                 SYSPRP setupdigetclassdevs failed with error 0
2018-09-16 20:44:02, Error                 SYSPRP MRTGeneralize:107 - ERROR: Failed DeleteInstance AntiSpywareProduct.instanceGuid="{D68DDC3A-831F-4FAE-9E44-DA132C1ACF46}" hr=2147749904
2018-09-16 20:44:02, Error                 SYSPRP MRTGeneralize:116 - ERROR: Failed DeleteInstance AntiVirusProduct.instanceGuid="{D68DDC3A-831F-4FAE-9E44-DA132C1ACF46}" hr=2147749904
2018-09-19 14:25:27, Error                 SYSPRP setupdigetclassdevs failed with error 0
2018-09-19 14:25:27, Error                 SYSPRP MRTGeneralize:107 - ERROR: Failed DeleteInstance AntiSpywareProduct.instanceGuid="{D68DDC3A-831F-4FAE-9E44-DA132C1ACF46}" hr=2147749904
2018-09-19 14:25:27, Error                 SYSPRP MRTGeneralize:116 - ERROR: Failed DeleteInstance AntiVirusProduct.instanceGuid="{D68DDC3A-831F-4FAE-9E44-DA132C1ACF46}" hr=2147749904

Seems like Windows Defender will be the cause of this

A reboot is necessary before the selectable update Windows-Defender of package Windows-Defender-Server-Core-Package can be turned off.

Also I tried to execute wmic product get identifyingnumber,name,vendor,version to see my current GUIDs but none of them matches {D68...

Will try your approach.

petemounce commented 6 years ago

@lmayorga1980 in my case, my provisioning was using Set-MpPreference to try to turn off that stuff; so, do something different from the default. I still haven't managed to get a successful sysprep. If you find a solution, I'd love to hear too. Likewise, if I do, I'll post an update.

adjackura commented 6 years ago

Have you tried a reboot after Set-MpPreference and before running sysprep? This seems like an issue with sysprep and Set-MpPreference if I understand the logs (maybe?).

lmayorga1980 commented 6 years ago

I did remove the features Uninstall-WindowsFeature Windows-Defender-Features and my problem was solved.

petemounce commented 6 years ago

@adjackura I'm reasonably sure I tried that, but I tried a set of things, so perhaps not.

@lmayorga1980 - I'm not sure I parsed that, sorry. Do you mean, you executed Uninstall-WindowsFeature Windows-Defender-Features before running gcesysprep and that solved your problem? Or, instead, you removed that from your setup, and that solved your problem?

lmayorga1980 commented 6 years ago

@petemounce, I got it removed from my setup and now I am back in business. Very interesting that the latest amazon ami from Windows 2016 contains the same error even before I customize it.

petemounce commented 5 years ago

I cut out my windows defender modification and that allowed a successful image. I still have those Failed DeleteInstance entries in my logs. Oh, Windows.