7
1
So this is a Windows 10 Pro 64 bit version 1607 system, Insider edition on a slow ring. Some days ago it was repeatedly failing KB3176934
with the same 0x800F0922
. I didn't find out the root cause and how to prevent it. My purpose is to find other who has exactly this same problem and figure out a solution. If someone already has a solution - even better.
Looking at the CBS directory, back from 08/26/2016 when the KB3176934
was failing I see a 22GB (!) log file. It seems like that there was "some" deadlock:
...
2016-08-26 20:18:37, Info CBS Session: 30539793_3012262845 initialized by client WindowsUpdateAgent, external staging directory: (null), external registry directory: (null
2016-08-26 20:18:37, Info CBS Opened cabinet package, package directory: \\?\C:\WINDOWS\SoftwareDistribution\Download\3717a62e3772d26d381fa9aea49eed42\, sandbox location: \\?\C:\WINDOWS\SoftwareDistribution\Download\3717a62e3772d26d381fa9aea49eed42\, cabinet location: \\?\C:\WINDOWS\SoftwareDistribution\Download\3717a62e3772d26d381fa9aea49eed42\Windows10.0-KB3176934-x64-EXPRESS.cab, manifest location: \\?\C:\WINDOWS\SoftwareDistribution\Download\3717a62e3772d26d381fa9aea49eed42\update.mum
2016-08-26 20:18:37, Info DPX Started DPX phase: Resume and Download Job
2016-08-26 20:18:37, Info DPX Started DPX phase: Apply Deltas Provided In File
2016-08-26 20:18:37, Info DPX Ended DPX phase: Apply Deltas Provided In File
2016-08-26 20:18:37, Info DPX Started DPX phase: Apply Deltas Provided In File
2016-08-26 20:18:37, Info DPX Ended DPX phase: Apply Deltas Provided In File
2016-08-26 20:18:37, Info DPX CJob::Resume completed with status: 0x0
2016-08-26 20:18:37, Info DPX Ended DPX phase: Resume and Download Job
2016-08-26 20:18:37, Info CBS Exec: Asynchrous operation, session completes later
2016-08-26 20:18:37, Info CBS Lock: Error found, inverse lock order, current lock held: CCbsExecutionCommunication, level: 130, lock attempted: CCbsWorkerQueue, level: 60. This will lead to a potential deadlock
2016-08-26 20:18:37, Info CBS Lock: Error found, inverse lock order, current lock held: CCbsExecutionCommunication, level: 130, lock attempted: CCbsWorkerQueue, level: 60. This will lead to a potential deadlock
2016-08-26 20:18:37, Info CBS Lock: Error found, inverse lock order, current lock held: CCbsSession, level: 66, lock attempted: CCbsWorkerQueue, level: 60. This will lead to a potential deadlock
2016-08-26 20:18:37, Info CBS Lock: Error found, inverse lock order, current lock held: CCbsExecutionCommunication, level: 130, lock attempted: CCbsWorkerQueue, level: 60. This will lead to a potential deadlock
2016-08-26 20:18:37, Info CBS Lock: Error found, inverse lock order, current lock held: CCbsSession, level: 66, lock attempted: CCbsWorkerQueue, level: 60. This will lead to a potential deadlock
2016-08-26 20:18:37, Info CBS Lock: Error found, inverse lock order, current lock held: CCbsExecutionCommunication, level: 130, lock attempted: CCbsWorkerQueue, level: 60. This will lead to a potential deadlock
2016-08-26 20:18:37, Info CBS Lock: Error found, inverse lock order, current lock held: CCbsExecutionCommunication, level: 130, lock attempted: CCbsWorkerQueue, level: 60. This will lead to a potential deadlock
2016-08-26 20:18:37, Info CBS Lock: Error found, inverse lock order, current lock held: CCbsSession, level: 66, lock attempted: CCbsWorkerQueue, level: 60. This will lead to a potential deadlock
2016-08-26 20:18:37, Info CBS Lock: Error found, inverse lock order, current lock held: CCbsExecutionCommunication, level: 130, lock attempted: CCbsWorkerQueue, level: 60. This will lead to a potential deadlock
...
This goes on for more than an hour taking up 22 GBs - talk about a tiny deadlock!
Moving onto 08/30/2016:
...
2016-08-30 15:16:03, Info CBS Opened cabinet package, package directory: \\?\C:\WINDOWS\SoftwareDistribution\Download\3717a62e3772d26d381fa9aea49eed42\, sandbox location: \\?\C:\WINDOWS\SoftwareDistribution\Download\3717a62e3772d26d381fa9aea49eed42\, cabinet location: \\?\C:\WINDOWS\SoftwareDistribution\Download\3717a62e3772d26d381fa9aea49eed42\Windows10.0-KB3176934-x64-EXPRESS.cab, manifest location: \\?\C:\WINDOWS\SoftwareDistribution\Download\3717a62e3772d26d381fa9aea49eed42\update.mum
2016-08-30 15:16:03, Info DPX Started DPX phase: Resume and Download Job
2016-08-30 15:16:03, Info DPX Started DPX phase: Apply Deltas Provided In File
2016-08-30 15:16:03, Info DPX Ended DPX phase: Apply Deltas Provided In File
2016-08-30 15:16:03, Info DPX CJob::Resume completed with status: 0x0
2016-08-30 15:16:03, Info DPX Ended DPX phase: Resume and Download Job
2016-08-30 15:16:03, Info DPX Extraction of file: update.ses failed because it is not present in the container (\\?\C:\WINDOWS\SoftwareDistribution\Download\3717a62e3772d26d381fa9aea49eed42\Windows10.0-KB3176934-x64-EXPRESS.cab).
2016-08-30 15:16:03, Info DPX DpxException hr=0x80070002 code=0x020109
2016-08-30 15:16:03, Info CBS Not able to add file to extract: update.ses [HRESULT = 0x80070002 - ERROR_FILE_NOT_FOUND] 2016-08-30 15:16:03, Info DPX Started DPX phase: Resume and Download Job
...happening multiple times and...
...
2016-09-01 19:28:39, Info CBS SQM: Package change report datapoints not populated because SQM is not initialized or not running online.
2016-09-01 19:28:39, Info CBS Reporting package change completion for package: Package_for_KB3189031~31bf3856ad364e35~amd64~~10.0.1.0, current: Installed, original: Absent, target: Installed, status: 0x0, failure source: Not Applicable, failure details: "(null)", client id: WindowsUpdateAgent, initiated offline: False, execution sequence: 93, first merged sequence: 93, pending decision: PendingAvoided_DelayQueueSideStepped, primitive execution context: Interactive Flight: False
2016-09-01 19:28:39, Info CBS The store corruption status report is incomplete. [HRESULT = 0x80070002 - ERROR_FILE_NOT_FOUND]
2016-09-01 19:28:39, Info CBS SQM: Package change report datapoints not populated because SQM is not initialized or not running online.
2016-09-01 19:28:39, Info CBS FinalCommitPackagesState: Completed persisting state of packages
...
whole bunch of this:
...
2016-09-02 14:07:33, Info CSI 000006cf One of the components setting this value is Microsoft-Windows-shell32, version 10.0.14393.103, arch amd64, nonSxS, pkt {l:8 b:31bf3856ad364e35}
2016-09-02 14:07:33, Info CSI 000006d0 Previously seen component setting this value is Microsoft-Windows-shell32, version 10.0.14393.103, arch Host= amd64 Guest= x86, nonSxS, pkt {l:8 b:31bf3856ad364e35}
2016-09-02 14:07:33, Info CSI 000006d1 Warning - Overlap: Registry value collision found under key \REGISTRY\MACHINE\SOFTWARE\Classes\AllSyncRootObjects\shell\ErrorResolution\ for MultiSelectModel, only one component should set this value
...
This is maybe not critical:
...
2016-09-02 14:07:58, Info CBS Progress: UI message updated. Operation type: Update. Stage: 0 out of 0. Percent progress: 10.
2016-09-02 14:07:58, Info CBS INSTALL index: 7, phase: 2, result 0, inf: input.inf
2016-09-02 14:07:58, Info CBS INSTALL index: 8, phase: 2, result 0, inf: stornvme.inf
2016-09-02 14:07:58, Info CBS INSTALL index: 9, phase: 2, result 0, inf: usbvideo.inf
2016-09-02 14:07:58, Info CBS INSTALL index: 0, phase: 3, result 0, inf: acpi.inf
2016-09-02 14:07:58, Info CBS INSTALL index: 1, phase: 3, result 0, inf: wnetvsc.inf
2016-09-02 14:07:58, Info CBS INSTALL index: 2, phase: 3, result 0, inf: wstorvsp.inf
2016-09-02 14:07:58, Info CBS INSTALL index: 3, phase: 3, result 0, inf: wvpcivsp.inf
2016-09-02 14:07:58, Info CBS INSTALL index: 4, phase: 3, result 0, inf: BthLEEnum.inf
2016-09-02 14:07:58, Info CBS INSTALL index: 5, phase: 3, result 0, inf: bth.inf
2016-09-02 14:07:58, Info CBS INSTALL index: 6, phase: 3, result 0, inf: xinputhid.inf
2016-09-02 14:07:59, Info CBS INSTALL index: 7, phase: 3, result 0, inf: input.inf
2016-09-02 14:07:59, Info CBS INSTALL index: 8, phase: 3, result 0, inf: stornvme.inf
2016-09-02 14:07:59, Info CBS INSTALL index: 9, phase: 3, result 0, inf: usbvideo.inf
2016-09-02 14:07:59, Info CBS DriverUpdateInstallUpdates failed [HRESULT = 0x80070bc2 - ERROR_SUCCESS_REBOOT_REQUIRED]
2016-09-02 14:07:59, Info CBS Doqe: System reboot required.
2016-09-02 14:07:59, Info CBS Perf: Doqe: Install ended.
2016-09-02 14:07:59, Info CBS Shtd: Non-critical driver operations completed successfully.
...
Trying some sid S-1-5-80-1448039036-2013904622-3830678473-3382385916-2632875139
which is not present in my system. And we are onto writing WER
, which looks like has trouble in itself:
...
2016-09-02 14:09:01, Info CSI 000002f4 Performing HKCU for sid: S-1-5-80-1448039036-2013904622-3830678473-3382385916-2632875139
2016-09-02 14:09:01, Error CSI 000002f5 (F) STATUS_OBJECT_NAME_NOT_FOUND #72233# from Windows::Rtl::SystemImplementation::DirectRegistryProvider::SysOpenKey(flg = (AllowAccessDenied), key = {provider=NULL, handle=0, name= ("null")}, da = (KEY_READ|KEY_WOW64_64KEY), oa = @0x46f1fbe60->OBJECT_ATTRIBUTES {s:48; rd:NULL; on:[78]'\Registry\USER\S-1-5-80-1448039036-2013904622-3830678473-3382385916-2632875139'; a:(OBJ_CASE_INSENSITIVE)}, disp = Unmapped disposition: 1864350776)[gle=0xd0000034]
2016-09-02 14:09:01, Error CSI 000002f6@2016/9/2:21:09:01.262 (F) onecore\base\wcp\sil\merged\ntu\ntsystem.cpp(5238): Error STATUS_OBJECT_NAME_NOT_FOUND originated in function Windows::Rtl::SystemImplementation::DirectRegistryProvider::SysOpenKey expression: (null) [gle=0x80004005]
2016-09-02 14:09:01, Info CBS Added C:\WINDOWS\Logs\CBS\CBS.log to WER report.
2016-09-02 14:09:01, Info CBS Added C:\WINDOWS\Logs\CBS\CbsPersist_20160830221525.log to WER report.
2016-09-02 14:09:01, Info CBS Startup: Changing logon timeout to a static timeout: 10800000
2016-09-02 14:09:01, Info CBS Added C:\WINDOWS\Logs\CBS\CbsPersist_20160827053046.log to WER report.
2016-09-02 14:09:01, Info CBS Added C:\WINDOWS\Logs\CBS\CbsPersist_20160827031613.log to WER report.
2016-09-02 14:09:01, Info CBS Added C:\WINDOWS\Logs\CBS\CbsPersist_20160826035948.cab to WER report.
2016-09-02 14:09:01, Info CBS Added C:\WINDOWS\Logs\CBS\CbsPersist_20160826022443.cab to WER report.
2016-09-02 14:09:01, Info CBS Could not get active session for current session file logging [HRESULT = 0x80004003 - E_POINTER]
2016-09-02 14:09:01, Info CBS Not able to add pending.xml.bad to Windows Error Report. [HRESULT = 0x80070002 - ERROR_FILE_NOT_FOUND]
2016-09-02 14:09:01, Error CSI 000002f7 (F) STATUS_OBJECT_NAME_NOT_FOUND #72232# from Windows::Rtl::SystemImplementation::DirectRegistryProvider::SysOpenKey(flg = 0, key = {provider=NULL, handle=0, name= ("null")}, da = (KEY_READ|KEY_WOW64_64KEY), oa = @0x46f1fbe60->OBJECT_ATTRIBUTES {s:48; rd:NULL; on:[78]'\Registry\USER\S-1-5-80-1448039036-2013904622-3830678473-3382385916-2632875139'; a:(OBJ_CASE_INSENSITIVE)}, disp = Unmapped disposition: 1864351756 [gle=0xd0000034]
2016-09-02 14:09:01, Error CSI 000002f8@2016/9/2:21:09:01.684 (F) onecore\base\wcp\sil\merged\ntu\ntsystem.cpp(5238): Error STATUS_OBJECT_NAME_NOT_FOUND originated in function Windows::Rtl::SystemImplementation::DirectRegistryProvider::SysOpenKey expression: (null)[gle=0x80004005]
2016-09-02 14:09:01, Info CBS Added C:\WINDOWS\Logs\CBS\CBS.log to WER report.
2016-09-02 14:09:01, Info CBS Added C:\WINDOWS\Logs\CBS\CbsPersist_20160830221525.log to WER report.
2016-09-02 14:09:01, Info CBS Added C:\WINDOWS\Logs\CBS\CbsPersist_20160827053046.log to WER report.
2016-09-02 14:09:01, Info CBS Added C:\WINDOWS\Logs\CBS\CbsPersist_20160827031613.log to WER report.
2016-09-02 14:09:01, Info CBS Added C:\WINDOWS\Logs\CBS\CbsPersist_20160826035948.cab to WER report.
2016-09-02 14:09:01, Info CBS Added C:\WINDOWS\Logs\CBS\CbsPersist_20160826022443.cab to WER report.
2016-09-02 14:09:01, Info CBS Could not get active session for current session file logging [HRESULT = 0x80004003 - E_POINTER]
2016-09-02 14:09:01, Info CBS Not able to add pending.xml.bad to Windows Error Report. [HRESULT = 0x80070002 - ERROR_FILE_NOT_FOUND]
...
seems like that the lack of this sid
fails the installer, which is the final error code in the Event Logs: 0x800f0922 - CBS_E_INSTALLERS_FAILED
:
...
2016-09-02 14:13:05, Error CBS Startup: Failed to process advanced operation queue, startupPhase: 0. A rollback transaction will be created. [HRESULT = 0x800f0922 - CBS_E_INSTALLERS_FAILED]
2016-09-02 14:13:05, Info CBS Setting ExecuteState key to: CbsExecuteStateInitiateRollback | CbsExecuteStateFlagAdvancedInstallersFailed
2016-09-02 14:13:05, Info CBS SetProgressMessage: progressMessageStage: -1, ExecuteState: CbsExecuteStateInitiateRollback | CbsExecuteStateFlagAdvancedInstallersFailed, SubStage: 0
2016-09-02 14:13:05, Info CBS Progress: UI message updated. Operation type: Update. Stage: 1 out of 1. Rollback.
...
Then with the recent KB3176938
I see similar errors:
...
2016-09-02 16:15:33, Info DPX Extraction of file: update.ses failed because it is not present in the container (\\?\C:\WINDOWS\SoftwareDistribution\Download\7dab6589581c4510df5e184be35f7c59\Windows10.0-KB3176938-x64-EXPRESS.cab).
2016-09-02 16:15:33, Info DPX DpxException hr=0x80070002 code=0x020109
2016-09-02 16:15:33, Info CBS Not able to add file to extract: update.ses [HRESULT = 0x80070002 - ERROR_FILE_NOT_FOUND]
2016-09-02 16:15:34, Info DPX Started DPX phase: Resume and Download Job
...
craziness
...
2016-09-02 19:05:26, Info CSI 000006d1 Warning - Overlap: Registry value collision found under key \REGISTRY\MACHINE\SOFTWARE\Classes\AllSyncRootObjects\shell\ErrorResolution\ for MultiSelectModel, only one component should set this value
2016-09-02 19:05:26, Info CSI 000006d2 One of the components setting this value is Microsoft-Windows-shell32, version 10.0.14393.103, arch amd64, nonSxS, pkt {l:8 b:31bf3856ad364e35}
2016-09-02 19:05:26, Info CSI 000006d3 Previously seen component setting this value is Microsoft-Windows-shell32, version 10.0.14393.103, arch Host= amd64 Guest= x86, nonSxS, pkt {l:8 b:31bf3856ad364e35}
...
Same non critical driver mishap:
...
2016-09-02 19:05:39, Info CBS Progress: UI message updated. Operation type: Update. Stage: 0 out of 0. Percent progress: 11.
2016-09-02 19:05:39, Info CBS INSTALL index: 9, phase: 2, result 0, inf: usbvideo.inf
2016-09-02 19:05:39, Info CBS INSTALL index: 0, phase: 3, result 0, inf: acpi.inf
2016-09-02 19:05:39, Info CBS INSTALL index: 1, phase: 3, result 0, inf: wnetvsc.inf
2016-09-02 19:05:39, Info CBS INSTALL index: 2, phase: 3, result 0, inf: wstorvsp.inf
2016-09-02 19:05:39, Info CBS INSTALL index: 3, phase: 3, result 0, inf: wvpcivsp.inf
2016-09-02 19:05:39, Info CBS INSTALL index: 4, phase: 3, result 0, inf: BthLEEnum.inf
2016-09-02 19:05:39, Info CBS INSTALL index: 5, phase: 3, result 0, inf: bth.inf
2016-09-02 19:05:39, Info CBS INSTALL index: 6, phase: 3, result 0, inf: xinputhid.inf
2016-09-02 19:05:40, Info CBS INSTALL index: 7, phase: 3, result 0, inf: input.inf
2016-09-02 19:05:40, Info CBS INSTALL index: 8, phase: 3, result 0, inf: stornvme.inf
2016-09-02 19:05:40, Info CBS INSTALL index: 9, phase: 3, result 0, inf: usbvideo.inf
2016-09-02 19:05:40, Info CBS DriverUpdateInstallUpdates failed [HRESULT = 0x80070bc2 - ERROR_SUCCESS_REBOOT_REQUIRED]
2016-09-02 19:05:40, Info CBS Doqe: System reboot required.
2016-09-02 19:05:40, Info CBS Perf: Doqe: Install ended.
2016-09-02 19:05:40, Info CBS Shtd: Non-critical driver operations completed successfully.
...
seems like again the lack of this sid
causes the rollback:
...
2016-09-02 19:06:43, Info CSI 000002f4 Performing HKCU for sid: S-1-5-80-1448039036-2013904622-3830678473-3382385916-2632875139
2016-09-02 19:06:43, Error CSI 000002f5 (F) STATUS_OBJECT_NAME_NOT_FOUND #72233# from Windows::Rtl::SystemImplementation::DirectRegistryProvider::SysOpenKey(flg = (AllowAccessDenied), key = {provider=NULL, handle=0, name= ("null")}, da = (KEY_READ|KEY_WOW64_64KEY), oa = @0x649a27c4f0->OBJECT_ATTRIBUTES {s:48; rd:NULL; on:[78]'\Registry\USER\S-1-5-80-1448039036-2013904622-3830678473-3382385916-2632875139'; a:(OBJ_CASE_INSENSITIVE)}, disp = Unmapped disposition: 2586297032)[gle=0xd0000034]
2016-09-02 19:06:43, Error CSI 000002f6@2016/9/3:02:06:43.692 (F) onecore\base\wcp\sil\merged\ntu\ntsystem.cpp(5238): Error STATUS_OBJECT_NAME_NOT_FOUND originated in function Windows::Rtl::SystemImplementation::DirectRegistryProvider::SysOpenKey expression: (null) [gle=0x80004005]
...
So maybe the key is the sid
S-1-5-80-1448039036-2013904622-3830678473-3382385916-2632875139
, but I cannot find anything about it with web searches.
The log files (CBS.zip): https://onedrive.live.com/?id=23A52F09515EBE7%216609&cid=023A52F09515EBE7
Downloaded the Anniversary Update (Windows10Upgrade28084.exe
) but it presents an empty dialog only with an Exit button.
Maybe the problem is that this KB3176938
is always in the "installed and restart needed" phase, so I'm not able to install other things? Just guessing...
Trying to force install the KB3176938 after manually downloaded the CAB
file.
Manually installing KB3176938 form a manually downloaded cabinet was not successful either. I was thinking maybe to start the install from safe mode, but the error comes really at the end of the install procedure, the computer restarted and again went to almost 100% progress. I feel like I'm in a 22-catch situation. First I'd like to stop the windows update from forcing this update.
See answer. After the repair with Windows10_InsiderPreview_Client_x64_en-us_14393.iso
I got KB3176934 and a couple of more updates. Seems to work fine now. Looking back, maybe at some point I did (or the system offered?) the anniversary update? Maybe that's not a good idea for an Insider Win10.
Comments are not for extended discussion; this conversation has been moved to chat.
– Mokubai – 2016-09-07T19:36:34.373Since the incident above I got into another update revert loop around the beginning of October. After a week of agony a user discovered that it was caused by an Xbox service. Note, that I don't have an Xbox. Microsoft prepared an installer for the registry fix for that problem. The installer only worked for the second try but solved the problem. – Csaba Toth – 2016-10-28T20:17:20.270