Greetings,
My Windows PCs are having trouble acquiring Windows Updates through my OpnSense router, and I'm not sure what's causing it. I'd love any thoughts folks could share.
- This is a home network trying to pull updates directly from Microsoft, not a WSUS setup.
- Prior to switching to OpnSense, I had no problems with Windows Updates on my Windows 10 machines via my Asus wireless router. Earlier this summer, I converted the Asus to a dumb AP and am using OpnSense as my router (Asus couldn't keep up with my gigabit fiber connection).
- Windows Updates (including Office updates) now either take agonizingly long amounts of time to download (hours or days) or simply fail with error 0x8024401c. Everything else about my connection is snappy besides updates.
- I can tether my laptop to my cell phone, and the updates come right down and do not fail. The failures only seem to happen through the connection involving my OpnSense setup. This makes me thing I've configured something wrong.
- I have IPv6 blocked in OpnSense.
- I am not using any kind of Proxy setup.
- IPS/IPD are turned off.
- Unbound blacklist is turned off.
My firewall rules are pretty basic, and my Windows 10 systems are on a VLAN with essentially no restrictions.
So what's going on from my PC? Here's a snippet from WindowsUpdate.log, hopefully with nothing personally identifiable:
2020/09/21 00:12:34.2381114 196 6164 Agent Added update 1E0E9CDD-90F0-48C8-A88E-3052EF3C600C.1 to search result
2020/09/21 00:12:34.2381281 196 6164 Agent Found 1 updates and 7 categories in search; evaluated appl. rules of 74 out of 73 deployed entities
2020/09/21 00:12:34.2395038 196 6164 Agent * END * Finding updates CallerId = MoUpdateOrchestrator, Id = 177, Exit code = 0x00000000 (cV = cWdiKb8NlUuxvUTV.0.1.1.0.2)
2020/09/21 00:12:34.2430181 196 6164 IdleTimer WU operation (CSearchCall::Init ID 177, operation # 1084) stopped; does use network; is not at background priority
2020/09/21 00:12:34.2430198 196 6164 IdleTimer Deactivate PDC state for Network
2020/09/21 00:12:34.2430907 196 6164 IdleTimer Decremented PDC RefCount for Network to 1
2020/09/21 00:12:34.2509265 10644 10740 ComApi *RESUMED* Search ClientId = MoUpdateOrchestrator, ServiceId = 8B24B027-1DEE-BABB-9A95-3517DFB9C552 (cV = cWdiKb8NlUuxvUTV.0.1.1.0)
2020/09/21 00:12:34.6345612 10644 10740 ComApi * END * Search ClientId = MoUpdateOrchestrator, Updates found = 1, ServiceId = 8B24B027-1DEE-BABB-9A95-3517DFB9C552 (cV = cWdiKb8NlUuxvUTV.0.1.1.0)
2020/09/21 00:12:34.6347947 10644 8028 ComApi * END * All federated searches have completed. Jobs = 2, Succeeded = 2, ClientId = MoUpdateOrchestrator (cV = cWdiKb8NlUuxvUTV.0.1.2)
2020/09/21 00:12:34.6424335 10644 11272 ComApi *FAILED* [80246007] ISusInternal:: IsCommitRequired
2020/09/21 00:12:34.7635152 196 6156 WIL *FAILED* [80070002] file = onecore\enduser\windowsupdate\client\engine\handler\osdeployment\installer\osinstaller.cpp, line = 587
2020/09/21 00:12:34.7635183 196 6156 WIL *FAILED* [80070002] file = onecore\enduser\windowsupdate\client\engine\handler\osdeployment\handler\uhosdeployment.cpp, line = 452
2020/09/21 00:12:34.7714946 196 6156 WIL *FAILED* [80070002] file = onecore\enduser\windowsupdate\client\engine\agent\updatemanager.cpp, line = 13616
2020/09/21 00:12:34.7718136 10644 11272 ComApi *FAILED* [80070002] ISusInternal:: IsCommitRequired
2020/09/21 00:12:34.7766928 10644 3204 ComApi Serializing CUpdate 1E0E9CDD-90F0-48C8-A88E-3052EF3C600C.1
2020/09/21 00:12:34.8257629 10644 3204 ComApi Update serialization complete. BSTR byte length = 3970733, CallbackInfo cookie length = 0
2020/09/21 00:12:34.9903624 10644 11272 ComApi * START * Federated Download ClientId = MoUpdateOrchestrator (cV = O8hm1TpZgEm/6Uv3.6.0)
2020/09/21 00:12:34.9905572 10644 7068 ComApi Federated Download: Starting download for 1 service(s) (cV = O8hm1TpZgEm/6Uv3.6.0)
2020/09/21 00:12:34.9906240 10644 7068 ComApi * START * Download ClientId = MoUpdateOrchestrator
2020/09/21 00:12:34.9906253 10644 7068 ComApi Flags: 0X1100C; Download priority: 2; Network Cost Policy: 0
2020/09/21 00:12:34.9906262 10644 7068 ComApi Updates in request: 1
2020/09/21 00:12:34.9906350 10644 7068 ComApi ServiceID = {8B24B027-1DEE-BABB-9A95-3517DFB9C552} Third party service
2020/09/21 00:12:35.2047485 196 6156 DownloadManager Subscribing to heartbeat event.
2020/09/21 00:12:35.2057254 10644 7068 ComApi *QUEUED* Download ClientId = MoUpdateOrchestrator
2020/09/21 00:12:59.7108859 196 1616 IdleTimer Activation callback for PDC handle 000002B3F29FA940 received (Reason: 100). Renewing activation...
2020/09/21 00:12:59.7108968 196 1616 IdleTimer Skipping renewal of PDC handle for Background operation CDynamicDownloadDataFetcher::FetchAndStoreDynamicData since it has been held for longer than 5 minutes. .
2020/09/21 00:13:10.0219269 196 10272 WebServices WS error: There was an error communicating with the endpoint at 'https://fe3cr.delivery.mp.microsoft.com/ClientWebService/client.asmx/secured'.
2020/09/21 00:13:10.0219299 196 10272 WebServices WS error: There was an error receiving the HTTP reply.
2020/09/21 00:13:10.0219312 196 10272 WebServices WS error: The operation did not complete within the time allotted.
2020/09/21 00:13:10.0219493 196 10272 WebServices WS error: The operation timed out
2020/09/21 00:13:10.0219546 196 10272 WebServices *FAILED* [8024401C] Web service call
2020/09/21 00:13:10.0219559 196 10272 WebServices Current service auth scheme=0.
2020/09/21 00:13:10.0219569 196 10272 WebServices Current Proxy auth scheme=0.
2020/09/21 00:13:12.0361213 196 10272 WebServices Auto proxy settings for this web service call.
2020/09/21 00:14:00.0645706 196 1616 IdleTimer Activation callback for PDC handle 000002B3F29FA940 received (Reason: 101). Renewing activation...
2020/09/21 00:14:00.0645848 196 1616 IdleTimer Skipping renewal of PDC handle for Background operation CDynamicDownloadDataFetcher::FetchAndStoreDynamicData since it has been held for longer than 5 minutes. .
2020/09/21 00:15:46.0103039 196 10272 WebServices WS error: There was an error communicating with the endpoint at 'https://fe3cr.delivery.mp.microsoft.com/ClientWebService/client.asmx/secured'.
2020/09/21 00:15:46.0103237 196 10272 WebServices WS error: There was an error receiving the HTTP reply.
2020/09/21 00:15:46.0103285 196 10272 WebServices WS error: The operation did not complete within the time allotted.
2020/09/21 00:15:46.0103602 196 10272 WebServices WS error: The operation timed out
2020/09/21 00:15:46.0103724 196 10272 WebServices *FAILED* [8024401C] Web service call
2020/09/21 00:15:46.0103762 196 10272 WebServices Current service auth scheme=0.
2020/09/21 00:15:46.0103790 196 10272 WebServices Current Proxy auth scheme=0.
2020/09/21 00:15:46.0103924 196 10272 DownloadManager GetExtendedUpdateInfo2 returned, hr=0x8024401C, FileLocations=0, FileDecryptionData=0
2020/09/21 00:15:46.0103974 196 10272 DownloadManager *FAILED* [8024401C] GetExtendedUpdateInfo2
2020/09/21 00:15:46.0104069 196 10272 DownloadManager DynamicDownloadDataFetcher - Failed to get extended update info2 for chunk: 0x8024401c
2020/09/21 00:15:46.0112947 196 10272 DownloadManager *FAILED* [8024401C] FetchAndStoreDynamicData failed
2020/09/21 00:15:46.0113164 196 10272 IdleTimer WU operation (CDynamicDownloadDataFetcher::FetchAndStoreDynamicData, operation # 1067) stopped; does use network; is at background priority
Note the various *FAILED* lines in there. The one I zeroed in on is the one that results in 0x8024401c:
WS error: There was an error communicating with the endpoint at 'https://fe3cr.delivery.mp.microsoft.com/ClientWebService/client.asmx/secured'.If I ping fe3cr.delivery.mp.microsoft.com, no response comes back. If I attempt to open it in Chrome, I get NET::ERR_CERTIFICATE_TRANSPARENCY_REQUIRED, "The server presented a certificate that was not publicly disclosed using the Certificate Transparency policy." Weird, because I'm not using a proxy server (unless there's one turned on somehow that I don't realize).
Watching my firewall log live view, nothing is being blocked during any of this that appears to be relevant. So, I'm at a loss. What the heck could be going on here?