Diagnosing a Windows Store connection problem


After Microsoft has rolled out a stable version of Windows 8.1 I wanted to have it installed on all my computers. The update went smoothly on my home desktop and a tablet but I had problems on a PC at work – the Store application could not connect to the Internet and I kept getting an error message: We weren’t able to connect to the Store. This might have happened because of a server problem or the network connection timed out. Please wait a few minutes and try again.. I was not able to find a solution on Google so I started my own investigation.

There were some error messages in Application Event Log, but they didn’t say much about what’s wrong. So I checked the Windows Store application log (C:\Users\admin\AppData\Local\Packages\WinStore_cw5n1h2txyewy\AC\Temp\winstore.log) and found few interesting lines:

2013-10-18 07:18:33.046, _Info_                WS   [00002384:00009404]
 CSQRProvider::GetData:  Entering for selector DiscoveryService.
2013-10-18 07:18:33.046, _Info_                WS   [00002384:00009404] 
 CHttpRequest::_CreateConnectionAndSendRequest: Server: go.microsoft.com, 
 URL /fwlink/?LinkID=195324&clcid=0x409
2013-10-18 07:18:33.066, _Error_               WS   [00002384:00009404] 
 CHttpConnectionCache::_CreateSession: WinHttpOpen failed: 5
2013-10-18 07:18:33.066, _Error_               WS   [00002384:00009404] 
 CHttpRequest::FetchResource: _CreateConnectionAndSendRequest failed: 0x80070005

The 0x80070005 code identifies an Access Denied error. Still, I didn’t know why WinHttpOpen was returning it. My next step was to run Process Monitor and look for Access Denied result codes. This is what I noticed:

error

Now everything started to make sense: WinHttpOpen couldn’t succeed because it wasn’t able to read the Internet settings (such as proxy configuration etc.). I compared permissions set on the HKLM\SOFTWARE\Microsoft\Windows\CurrentVersion\Internet Settings registry key between my home desktop and the work PC and found one difference. My work PC was missing read rights for ALL APPLICATION PACKAGES group (SID: S-1-15-2-1, more information here). This SID is used by applications that are running using web context (hosted by WWAHost.exe) when they access system resources. After adding read permissions for this group Windows Store started running correctly and I was able to update to 8.1 🙂 You may ask why my registry was badly configured. The answer could be found in a report generated by gpresult: gpresult /h c:\temp\gpreport.html. The policies applied by my company Domain Controllers altered the default registry permissions on the Internet Settings key. Administrators apparently forgot about Windows 8 systems that are part of their domain and propagated settings for older versions of Windows.

To summarize, if you ever run into connectivity issues in Windows Store apps, make sure that you have valid permissions set for ALL APPLICATION PACKAGES group on system folders and registry keys (all valid permissions can be found here).

6 thoughts on “Diagnosing a Windows Store connection problem

  1. I’m following your blog for a couple of years now and I’m still wondering where do you get all this information and knowledge. Respect to you.

    Ondrej

    1. Thanks Ondrej – I’m reading a lot (mostly blogs and books about diagnostics) and trying to apply what I’ve read 🙂 BTW. your comment is really encouraging and made me smile – thanks once again! 🙂

      1. Can you point me to some books that you have found the most useful? I hope I could help you someway one day.

      2. For .NET I would recommend: CLR via C# and Advanced .NET Debugging (when you read it, try to practise all the examples in windbg). For Windows the best book I’ve read was Inside Windows Debugging. Not bad was also Advanced Windows Debugging. And when you want to know some part of Windows deeply check Windows Internals (though it might be hard at first sight). If you like video tutorials you may check plurasight for courses on Windows debugging and Internals and free Channel 9 series entitled Defrag Tools by Andrew Richards (just great:))

  2. I’ve been having this issue for many months. I’m just now wanting to upgrade to Windows 8.1, but was never able to do so because the Store app (and several others) simply wouldn’t open or function. Here’s my winstore.log file:
    2014-02-24 00:15:36.810, _Info_ WS [00002192:00001064] ***********************************************************************
    2014-02-24 00:15:36.810, _Info_ WS [00002192:00001064] Process name: C:\Windows\System32\WWAHost.exe
    2014-02-24 00:15:36.810, _Info_ WS [00002192:00001064] User name: BRIAN-PC\Brian
    2014-02-24 00:15:36.811, _Info_ WS [00002192:00001064] Computer name: BRIAN-PC
    2014-02-24 00:15:36.811, _Info_ WS [00002192:00001064] Windows build: 9200.16628.amd64fre.win8_gdr.130531-1504
    2014-02-24 00:15:36.811, _Info_ WS [00002192:00001064] Client version: 670
    2014-02-24 00:15:36.811, _Info_ WS [00002192:00001064] WinStoreUI QFE version: 1
    2014-02-24 00:15:36.812, _Info_ WS [00002192:00001064] Switched to view state: FullScreenLandscape
    2014-02-24 00:15:36.819, _Info_ WS [00002192:00001064] CNetworkState::_Initialize: NLM_CONNECTION_COST flags initalized to 0x00000001
    2014-02-24 00:15:36.819, _Info_ WS [00002192:00001064] CNetworkState::_GetDataPlanStatus: MaxDownloadSize = -1, DataLimit = -1, Usage = -1
    2014-02-24 00:15:36.821, _Info_ WS [00002192:00001112] ***********************************************************************
    2014-02-24 00:15:36.821, _Info_ WS [00002192:00001112] Process name: C:\Windows\System32\WWAHost.exe
    2014-02-24 00:15:36.822, _Info_ WS [00002192:00001112] User name: BRIAN-PC\Brian
    2014-02-24 00:15:36.822, _Info_ WS [00002192:00001112] Computer name: BRIAN-PC
    2014-02-24 00:15:36.822, _Info_ WS [00002192:00001112] Windows build: 9200.16628.amd64fre.win8_gdr.130531-1504
    2014-02-24 00:15:36.822, _Info_ WS [00002192:00001112] Client version: 670
    2014-02-24 00:15:36.822, _Info_ WS [00002192:00001112] WinStoreUI QFE version: 1
    2014-02-24 00:15:36.825, _Info_ WS [00002192:00001064] Globals::InitializePhase1: user is NOT opted in to BI
    2014-02-24 00:15:36.825, _Info_ WS [00002192:00001064] DiscoveryService::SetOSInfo(): Edition: edition, Type: type
    2014-02-24 00:15:36.825, _Info_ WS [00002192:00001064] DiscoveryService::SetOSInfo(): Edition: ProfessionalWMC, Type: Retail
    2014-02-24 00:15:36.825, _Info_ WS [00002192:00003116] WinStoreCache::DoQuery: Provider 1: Cache miss for GetOSEditionInfo.
    2014-02-24 00:15:36.827, _Info_ WS [00002192:00001064] CWinStore::_BlockSuspend: 1
    2014-02-24 00:15:36.829, _Info_ WS [00002192:00002356] WinStoreCache::DoQuery: Provider 0: Cache miss for DiscoveryService.
    2014-02-24 00:15:36.829, _Info_ WS [00002192:00002700] WinStoreCache::DoQuery: Provider 3: Cache miss for DigitalMarker.
    2014-02-24 00:15:36.829, _Info_ WS [00002192:00002356] CSQRProvider::GetData: Entering for selector DiscoveryService.
    2014-02-24 00:15:36.829, _Info_ WS [00002192:00002700] CCommerceProvider::GetData: Entering for selector DigitalMarker.
    2014-02-24 00:15:36.829, _Info_ WS [00002192:00002356] CHttpRequest::_CreateConnectionAndSendRequest: Server: go.microsoft.com, URL /fwlink/?LinkID=195324&clcid=0x409
    2014-02-24 00:15:36.829, _Info_ WS [00002192:00006664] WinStoreCache::DoQuery: Provider 4: Cache miss for PrefetchParentalControls.
    2014-02-24 00:15:36.830, _Info_ WS [00002192:00002356] CHttpConnectionCache::GetSession: New session handle 0x000000EE4E3DF670
    2014-02-24 00:15:36.830, _Info_ WS [00002192:00002356] CHttpConnectionCache::OnNewConnection: Caching handle 0x4f027c40 for go.microsoft.com:443
    2014-02-24 00:15:36.830, _Info_ WS [00002192:00002356] CHttpRequest::_CreateConnectionAndSendRequest: hRequest 0x4f01bdb0 is for GET /fwlink/?LinkID=195324&clcid=0x409
    2014-02-24 00:15:36.831, _Info_ WS [00002192:00006664] WinStoreCache::DoQuery: Provider 4 returned 0 bytes (0x00000000) for PrefetchParentalControls
    2014-02-24 00:15:36.833, _Warning_ WS [00002192:00002356] CHttpRequest::_GetProxyInfoForUrl: Autoproxy failed: 0x80072f94
    2014-02-24 00:15:36.833, _Info_ WS [00002192:00002356] Proxy list = (null), Proxy bypass = (null), Proxy access type = 0
    2014-02-24 00:15:36.833, _Info_ WS [00002192:00002356] CHttpRequest::_SendRequest: Calling WinHttpSendRequest, hRequest 0x4f01bdb0 attempt 1
    2014-02-24 00:15:36.835, _Error_ WS [00002192:00006664] Request 0x4f01bdb0 failed, error 12007 for result 5
    2014-02-24 00:15:36.835, _Info_ WS [00002192:00002356] CHttpRequest::_SendRequest: WinHttpSendRequest hRequest 0x4f01bdb0 (1) result: 0x80072ee7, proxy time: 0
    2014-02-24 00:15:36.835, _Info_ WS [00002192:00002356] CHttpConnectionCache::CloseConnection: Closing handle 0x4f027c40 for go.microsoft.com:443
    2014-02-24 00:15:36.835, _Error_ WS [00002192:00002356] CHttpRequest::FetchResource: _CreateConnectionAndSendRequest failed: 0x80072ee7
    2014-02-24 00:15:36.835, _Info_ WS [00002192:00002356] CSQRProvider::GetData: Leaving for selector DiscoveryService with result code 0x80004005.
    2014-02-24 00:15:36.835, _Warning_ WS [00002192:00002356] WinStoreCache::DoQuery: Provider 0 returned failure for DiscoveryService, hr=0x80004005
    2014-02-24 00:15:36.855, _Info_ WS [00002192:00001064] CNoOpSink::OnEvent: hrEvent = 0x00000000
    2014-02-24 00:15:36.855, _Info_ WS [00002192:00001064] CWinStore::_UnblockSuspend: 0
    2014-02-24 00:15:36.855, _Error_ WS [00002192:00001064] CWinStore::_NavigateToErrorPage: We weren’t able to connect to the Store. This might have happened because of a server problem or the network connection timed out. Please wait a few minutes and try again.
    2014-02-24 00:15:38.054, _Info_ WS [00002192:00003116] WinStoreCache::DoQuery: Provider 1 returned 648 bytes (0x49ea2b40) for GetOSEditionInfo
    2014-02-24 00:15:38.058, _Info_ WS [00002192:00002720] WindowsStoreCache::DoCheckCacheDiskUsage: Disk usage is 0.000001 percent
    2014-02-24 00:15:38.079, _Info_ WS [00002192:00002700] DebugHeader: GetData:
    2014-02-24 00:15:38.079, _Info_ WS [00002192:00002700] WinStoreCache::DoQuery: Provider 3 returned 5218 bytes (0x4f080230) for DigitalMarker
    2014-02-24 00:15:38.807, _Info_ WS [00002192:00001064] visibilityState changed to: hidden
    I’ve tried just about every possible solution that people have been posting with no success. Maybe I’m just missing something somewhere?

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s