OPNsense Forum

Archive => 20.7 Legacy Series => Topic started by: wondercow on September 22, 2020, 06:10:10 pm

Title: Problems downloading Windows Updates through OpnSense
Post by: wondercow on September 22, 2020, 06:10:10 pm

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:

Code: [Select]

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:

Code: [Select]

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?